Sep 25 14:05:38 VERBOSE[2796] logger.c: -- Starting simple switch on 'Zap/1-1'
Sep 25 14:05:46 WARNING[2796] chan_zap.c: CallerID returned with error on channel 'Zap/1-1'
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing NoOp("Zap/1-1", "Entering from-zaptel with DID == ") in new stack
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing Ringing("Zap/1-1", "") in new stack
Sep 25 14:05:46 DEBUG[2796] chan_zap.c: Requested indication 3 on channel Zap/1-1
Sep 25 14:05:46 DEBUG[2796] pbx.c: Expression result is '1'
Sep 25 14:05:46 DEBUG[2796] pbx.c: Function result is 's'
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing Set("Zap/1-1", "DID=s") in new stack
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing NoOp("Zap/1-1", "DID is now s") in new stack
Sep 25 14:05:46 DEBUG[2796] pbx.c: Expression result is '1'
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing GotoIf("Zap/1-1", "1?zapok:notzap") in new stack
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Goto (from-zaptel,s,8)
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing NoOp("Zap/1-1", "Is a Zaptel Channel") in new stack
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing Set("Zap/1-1", "CHAN=1-1") in new stack
Sep 25 14:05:46 DEBUG[2796] pbx.c: Function result is '1'
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing Set("Zap/1-1", "CHAN=1") in new stack
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing Macro("Zap/1-1", "from-zaptel-1|s|1") in new stack
Sep 25 14:05:46 WARNING[2796] app_macro.c: No such context 'macro-from-zaptel-1' for macro 'from-zaptel-1'
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing NoOp("Zap/1-1", "Returned from Macro from-zaptel-1") in new stack
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing Goto("Zap/1-1", "from-pstn|s|1") in new stack
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Goto (from-pstn,s,1)
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing NoOp("Zap/1-1", "No DID or CID Match") in new stack
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing Answer("Zap/1-1", "") in new stack
Sep 25 14:05:46 DEBUG[2796] chan_zap.c: Took Zap/1-1 off hook
Sep 25 14:05:46 DEBUG[2796] chan_zap.c: Enabled echo cancellation on channel 1
Sep 25 14:05:46 DEBUG[2796] chan_zap.c: Engaged echo training on channel 1
Sep 25 14:05:46 VERBOSE[2796] logger.c: -- Executing Wait("Zap/1-1", "2") in new stack
Sep 25 14:05:48 DEBUG[2796] chan_zap.c: Exception on 14, channel 1
Sep 25 14:05:48 DEBUG[2796] chan_zap.c: Got event Ring/Answered(2) on channel 1 (index 0)
Sep 25 14:05:48 DEBUG[2796] chan_zap.c: Setting IDLE polarity due to ring. Old polarity was 0
Sep 25 14:05:48 WARNING[2796] chan_zap.c: Ring/Off-hook in strange state 6 on channel 1
Sep 25 14:05:48 VERBOSE[2796] logger.c: -- Executing Playback("Zap/1-1", "ss-noservice") in new stack
Sep 25 14:05:48 DEBUG[2796] channel.c: Scheduling timer at 160 sample intervals
Sep 25 14:05:48 VERBOSE[2796] logger.c: -- Playing 'ss-noservice' (language 'en')
Sep 25 14:05:53 DEBUG[2796] channel.c: Scheduling timer at 0 sample intervals
Sep 25 14:05:53 DEBUG[2796] channel.c: Scheduling timer at 0 sample intervals
Sep 25 14:05:53 VERBOSE[2796] logger.c: -- Executing SayAlpha("Zap/1-1", "") in new stack
Sep 25 14:06:03 WARNING[2796] pbx.c: Timeout, but no rule 't' in context 'from-pstn'
Sep 25 14:06:03 DEBUG[2796] chan_zap.c: Hangup: channel: 1 index = 0, normal = 14, callwait = -1, thirdcall = -1
Sep 25 14:06:03 DEBUG[2796] chan_zap.c: disabled echo cancellation on channel 1
Sep 25 14:06:03 DEBUG[2796] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1
Sep 25 14:06:03 DEBUG[2796] chan_zap.c: Updated conferencing on 1, with 0 conference users
Sep 25 14:06:03 VERBOSE[2796] logger.c: -- Hungup 'Zap/1-1'
Sep 25 14:06:03 ERROR[2796] cdr_addon_mysql.c: cdr_mysql: Unknown connection error: (2006) MySQL server has gone away
Sep 25 14:06:03 DEBUG[2796] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Sep 25 14:06:03 DEBUG[2796] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode) VALUES ('2007-09-25 14:05:46','','','s','from-pstn', 'Zap/1-1','','SayAlpha','',17,17,'ANSWERED',3,'')
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '(null)'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '(null)'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is 's'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is 'from-pstn'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is 'Zap/1-1'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '(null)'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is 'SayAlpha'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '(null)'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '2007-09-25 14:05:46'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '2007-09-25 14:05:46'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '2007-09-25 14:06:03'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '17'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '17'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is 'ANSWERED'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is 'DOCUMENTATION'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '(null)'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '1190743538.22'
Sep 25 14:06:03 DEBUG[2796] pbx.c: Function result is '(null)'