rendered paste bodySep 5 23:29:32 VERBOSE[20468] logger.c: -- Accepting AUTHENTICATED call from 207.174.202.3:
> requested format = unknown,
> requested prefs = (g729|ulaw|g726|gsm),
> actual format = g729,
> host prefs = (g729|ulaw|gsm),
> priority = mine
Sep 5 23:29:32 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "FROM_DID=3147324351") in new stack
Sep 5 23:29:32 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "FAX_RX=disabled") in new stack
Sep 5 23:29:32 VERBOSE[24131] logger.c: -- Executing Goto("IAX2/teliax-sb-1", "timeconditions|1|1") in new stack
Sep 5 23:29:32 VERBOSE[24131] logger.c: -- Goto (timeconditions,1,1)
Sep 5 23:29:32 VERBOSE[24131] logger.c: -- Executing GotoIfTime("IAX2/teliax-sb-1", "10:00-18:00|mon-fri|*|*?ivr-3|s|1") in new stack
Sep 5 23:29:32 VERBOSE[24131] logger.c: -- Executing Goto("IAX2/teliax-sb-1", "ivr-10|s|1") in new stack
Sep 5 23:29:32 VERBOSE[24131] logger.c: -- Goto (ivr-10,s,1)
Sep 5 23:29:32 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "LOOPCOUNT=0") in new stack
Sep 5 23:29:32 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "__DIR-CONTEXT=default") in new stack
Sep 5 23:29:32 VERBOSE[24131] logger.c: -- Executing Answer("IAX2/teliax-sb-1", "") in new stack
Sep 5 23:29:32 DEBUG[20460] channel.c: Avoiding initial deadlock for 'IAX2/teliax-sb-1'
Sep 5 23:29:32 VERBOSE[24131] logger.c: -- Executing Wait("IAX2/teliax-sb-1", "1") in new stack
Sep 5 23:29:32 DEBUG[20468] chan_iax2.c: Ooh, voice format changed to 256
Sep 5 23:29:33 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "TIMEOUT(digit)=3") in new stack
Sep 5 23:29:33 VERBOSE[24131] logger.c: -- Digit timeout set to 3
Sep 5 23:29:33 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "TIMEOUT(response)=10") in new stack
Sep 5 23:29:33 VERBOSE[24131] logger.c: -- Response timeout set to 10
Sep 5 23:29:33 VERBOSE[24131] logger.c: -- Executing BackGround("IAX2/teliax-sb-1", "custom/closed") in new stack
Sep 5 23:29:33 VERBOSE[24131] logger.c: -- Playing 'custom/closed' (language 'en')
Sep 5 23:29:35 DEBUG[24131] pbx.c: Oooh, got something to jump out with ('1')!
Sep 5 23:29:36 VERBOSE[24131] logger.c: == CDR updated on IAX2/teliax-sb-1
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Macro("IAX2/teliax-sb-1", "exten-vm|1000|1000") in new stack
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Macro("IAX2/teliax-sb-1", "user-callerid") in new stack
Sep 5 23:29:36 DEBUG[24131] pbx.c: Expression result is '0'
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing GotoIf("IAX2/teliax-sb-1", "0?report") in new stack
Sep 5 23:29:36 DEBUG[24131] pbx.c: Not taking any branch
Sep 5 23:29:36 DEBUG[24131] pbx.c: Expression result is '0'
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing GotoIf("IAX2/teliax-sb-1", "0?start") in new stack
Sep 5 23:29:36 DEBUG[24131] pbx.c: Not taking any branch
Sep 5 23:29:36 DEBUG[24131] pbx.c: Function result is '3035212488'
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "REALCALLERIDNUM=3035212488") in new stack
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing NoOp("IAX2/teliax-sb-1", "REALCALLERIDNUM is 3035212488") in new stack
Sep 5 23:29:36 DEBUG[24131] db.c: Unable to find key '3035212488/user' in family 'DEVICE'
Sep 5 23:29:36 DEBUG[24131] func_db.c: DB: DEVICE/3035212488/user not found in database.
Sep 5 23:29:36 DEBUG[24131] pbx.c: Function result is ''
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "AMPUSER=") in new stack
Sep 5 23:29:36 DEBUG[24131] db.c: Unable to find key '/cidname' in family 'AMPUSER'
Sep 5 23:29:36 DEBUG[24131] func_db.c: DB: AMPUSER//cidname not found in database.
Sep 5 23:29:36 DEBUG[24131] pbx.c: Function result is ''
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "AMPUSERCIDNAME=") in new stack
Sep 5 23:29:36 DEBUG[24131] pbx.c: Expression result is '1'
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing GotoIf("IAX2/teliax-sb-1", "1?report") in new stack
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Goto (macro-user-callerid,s,9)
Sep 5 23:29:36 DEBUG[24131] pbx.c: Function result is '"PCS Phone CO" <3035212488>'
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing NoOp("IAX2/teliax-sb-1", "Using CallerID "PCS Phone CO" <3035212488>") in new stack
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "FROMCONTEXT=exten-vm") in new stack
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "VMBOX=1000") in new stack
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "EXTTOCALL=1000") in new stack
Sep 5 23:29:36 DEBUG[24131] db.c: Unable to find key '1000' in family 'CFU'
Sep 5 23:29:36 DEBUG[24131] func_db.c: DB: CFU/1000 not found in database.
Sep 5 23:29:36 DEBUG[24131] pbx.c: Function result is ''
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "CFUEXT=") in new stack
Sep 5 23:29:36 DEBUG[24131] pbx.c: Expression result is '1'
Sep 5 23:29:36 DEBUG[24131] pbx.c: Expression result is '0'
Sep 5 23:29:36 DEBUG[24131] pbx.c: Expression result is '1'
Sep 5 23:29:36 DEBUG[24131] pbx.c: Function result is '30'
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "RT=30") in new stack
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Macro("IAX2/teliax-sb-1", "record-enable|1000|IN") in new stack
Sep 5 23:29:36 DEBUG[24131] pbx.c: Function result is '0'
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing GotoIf("IAX2/teliax-sb-1", "0 > 0?2:4") in new stack
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Goto (macro-record-enable,s,4)
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing DeadAGI("IAX2/teliax-sb-1", "recordingcheck|20060905-232936|1157516972.246") in new stack
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Sep 5 23:29:36 VERBOSE[24131] logger.c: recordingcheck|20060905-232936|1157516972.246: Inbound recording not enabled
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- AGI Script recordingcheck completed, returning 0
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing NoOp("IAX2/teliax-sb-1", "No recording needed") in new stack
Sep 5 23:29:36 DEBUG[24131] pbx.c: Expression result is '0'
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing GotoIf("IAX2/teliax-sb-1", "0?dolocaldial|1") in new stack
Sep 5 23:29:36 DEBUG[24131] pbx.c: Not taking any branch
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Macro("IAX2/teliax-sb-1", "dial|30|tr|1000") in new stack
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing AGI("IAX2/teliax-sb-1", "dialparties.agi") in new stack
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Sep 5 23:29:36 VERBOSE[24131] logger.c: dialparties.agi: Starting New Dialparties.agi
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- dialparties.agi: priority is 1
Sep 5 23:29:36 VERBOSE[24131] logger.c: dialparties.agi: Caller ID name is 'PCS Phone CO' number is '3035212488'
Sep 5 23:29:36 VERBOSE[24131] logger.c: dialparties.agi: Methodology of ring is 'none'
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- dialparties.agi: Added extension 1000 to extension map
Sep 5 23:29:36 DEBUG[24131] db.c: Unable to find key '1000' in family 'CF'
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- dialparties.agi: Extension 1000 cf is disabled
Sep 5 23:29:36 DEBUG[24131] db.c: Unable to find key '1000' in family 'DND'
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- dialparties.agi: Extension 1000 do not disturb is disabled
Sep 5 23:29:36 DEBUG[24131] db.c: Unable to find key '1000' in family 'CW'
Sep 5 23:29:36 DEBUG[24131] db.c: Unable to find key '1000' in family 'CFB'
Sep 5 23:29:36 DEBUG[24131] db.c: Unable to find key '1000' in family 'CFU'
Sep 5 23:29:36 VERBOSE[24131] logger.c: > dialparties.agi: extnum: 1000
Sep 5 23:29:36 VERBOSE[24131] logger.c: > dialparties.agi: exthascw: 0
Sep 5 23:29:36 VERBOSE[24131] logger.c: > dialparties.agi: exthascfb: 0
Sep 5 23:29:36 VERBOSE[24131] logger.c: > dialparties.agi: extcfb:
Sep 5 23:29:36 VERBOSE[24131] logger.c: > dialparties.agi: exthascfu: 0
Sep 5 23:29:36 VERBOSE[24131] logger.c: > dialparties.agi: extcfu:
Sep 5 23:29:36 DEBUG[24136] manager.c: Manager received command 'login'
Sep 5 23:29:36 VERBOSE[24136] logger.c: == Parsing '/etc/asterisk/manager.conf': Sep 5 23:29:36 VERBOSE[24136] logger.c: == Parsing '/etc/asterisk/manager.conf': Found
Sep 5 23:29:36 VERBOSE[24136] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Sep 5 23:29:36 VERBOSE[24136] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': Found
Sep 5 23:29:36 WARNING[24136] config.c: Unknown directive 'permit=192.168.1.0/255.255.255.0' at line 18 of manager_custom.conf
Sep 5 23:29:36 DEBUG[24136] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer
Sep 5 23:29:36 DEBUG[24136] acl.c: 127.0.0.1/255.255.255.0/255.255.255.0 appended to acl for peer
Sep 5 23:29:36 DEBUG[24136] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0
Sep 5 23:29:36 DEBUG[24136] acl.c: ##### Testing 127.0.0.1 with 127.0.0.0
Sep 5 23:29:36 VERBOSE[24136] logger.c: == Manager 'admin' logged on from 127.0.0.1
Sep 5 23:29:36 DEBUG[24136] manager.c: Manager received command 'ExtensionState'
Sep 5 23:29:36 DEBUG[24136] manager.c: Manager received command 'Logoff'
Sep 5 23:29:36 VERBOSE[24136] logger.c: == Manager 'admin' logged off from 127.0.0.1
Sep 5 23:29:36 VERBOSE[24131] logger.c: > dialparties.agi: ExtensionState: 0
Sep 5 23:29:36 VERBOSE[24131] logger.c: dialparties.agi: Extension 1000 has ExtensionState: 0
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 1000
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- dialparties.agi: DbSet CALLTRACE/1000 to 3035212488
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- AGI Script dialparties.agi completed, returning 0
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Executing Dial("IAX2/teliax-sb-1", "SIP/1000|30|tr") in new stack
Sep 5 23:29:36 DEBUG[24131] chan_sip.c: Setting NAT on RTP to 524288
Sep 5 23:29:36 DEBUG[24131] acl.c: ##### Testing 69.47.46.168 with 10.0.1.0
Sep 5 23:29:36 DEBUG[24131] chan_sip.c: Target address 69.47.46.168 is not local, substituting externip
Sep 5 23:29:36 DEBUG[24131] chan_sip.c: Outgoing Call for 1000
Sep 5 23:29:36 VERBOSE[24131] logger.c: -- Called 1000
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Nobody picked up in 30000 ms
Sep 5 23:30:07 DEBUG[24131] chan_sip.c: update_call_counter(1000) - decrement call limit counter
Sep 5 23:30:07 DEBUG[24131] chan_sip.c: Acked pending invite 102
Sep 5 23:30:07 DEBUG[24131] chan_sip.c: Stopping retransmission on '355aeddc50ec628651ee8e375cbd18a2@66.128.119.107' of Request 102: Match Found
Sep 5 23:30:07 DEBUG[24131] app_dial.c: Exiting with DIALSTATUS=NOANSWER.
Sep 5 23:30:07 DEBUG[24131] pbx.c: Expression result is '1'
Sep 5 23:30:07 DEBUG[24131] pbx.c: Expression result is '0'
Sep 5 23:30:07 DEBUG[24131] pbx.c: Expression result is '0'
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing GosubIf("IAX2/teliax-sb-1", "0?docfu|1") in new stack
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing NoOp("IAX2/teliax-sb-1", "Voicemail is 1000") in new stack
Sep 5 23:30:07 DEBUG[24131] pbx.c: Expression result is '0'
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing GotoIf("IAX2/teliax-sb-1", "0?s-NOANSWER|1") in new stack
Sep 5 23:30:07 DEBUG[24131] pbx.c: Not taking any branch
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing NoOp("IAX2/teliax-sb-1", "Sending to Voicemail box 1000") in new stack
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing Macro("IAX2/teliax-sb-1", "vm|1000|NOANSWER") in new stack
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing Macro("IAX2/teliax-sb-1", "user-callerid") in new stack
Sep 5 23:30:07 DEBUG[24131] pbx.c: Expression result is '0'
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing GotoIf("IAX2/teliax-sb-1", "0?report") in new stack
Sep 5 23:30:07 DEBUG[24131] pbx.c: Not taking any branch
Sep 5 23:30:07 DEBUG[24131] pbx.c: Expression result is '1'
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing GotoIf("IAX2/teliax-sb-1", "1?start") in new stack
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Goto (macro-user-callerid,s,4)
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing NoOp("IAX2/teliax-sb-1", "REALCALLERIDNUM is 3035212488") in new stack
Sep 5 23:30:07 DEBUG[24131] db.c: Unable to find key '3035212488/user' in family 'DEVICE'
Sep 5 23:30:07 DEBUG[24131] func_db.c: DB: DEVICE/3035212488/user not found in database.
Sep 5 23:30:07 DEBUG[24131] pbx.c: Function result is ''
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "AMPUSER=") in new stack
Sep 5 23:30:07 DEBUG[24131] db.c: Unable to find key '/cidname' in family 'AMPUSER'
Sep 5 23:30:07 DEBUG[24131] func_db.c: DB: AMPUSER//cidname not found in database.
Sep 5 23:30:07 DEBUG[24131] pbx.c: Function result is ''
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "AMPUSERCIDNAME=") in new stack
Sep 5 23:30:07 DEBUG[24131] pbx.c: Expression result is '1'
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing GotoIf("IAX2/teliax-sb-1", "1?report") in new stack
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Goto (macro-user-callerid,s,9)
Sep 5 23:30:07 DEBUG[24131] pbx.c: Function result is '"PCS Phone CO" <3035212488>'
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing NoOp("IAX2/teliax-sb-1", "Using CallerID "PCS Phone CO" <3035212488>") in new stack
Sep 5 23:30:07 DEBUG[24131] pbx.c: Expression result is '0'
Sep 5 23:30:07 DEBUG[24131] pbx.c: Function result is ''
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "VMGAIN=") in new stack
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing Goto("IAX2/teliax-sb-1", "s-NOANSWER|1") in new stack
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Goto (macro-vm,s-NOANSWER,1)
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing Macro("IAX2/teliax-sb-1", "get-vmcontext|1000") in new stack
Sep 5 23:30:07 DEBUG[24131] pbx.c: Function result is 'default'
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing Set("IAX2/teliax-sb-1", "VMCONTEXT=default") in new stack
Sep 5 23:30:07 DEBUG[24131] pbx.c: Expression result is '0'
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing GotoIf("IAX2/teliax-sb-1", "0?200:300") in new stack
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Goto (macro-get-vmcontext,s,300)
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing NoOp("IAX2/teliax-sb-1", "") in new stack
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Executing VoiceMail("IAX2/teliax-sb-1", "1000@default|u") in new stack
Sep 5 23:30:07 DEBUG[24131] app_voicemail.c: /var/spool/asterisk/voicemail/default/1000/unavail doesn't exist, doing what we can
Sep 5 23:30:07 VERBOSE[24131] logger.c: -- Playing 'vm-theperson' (language 'en')
Sep 5 23:30:09 VERBOSE[24131] logger.c: -- Playing 'digits/1' (language 'en')
Sep 5 23:30:09 VERBOSE[24131] logger.c: -- Playing 'digits/0' (language 'en')
Sep 5 23:30:10 VERBOSE[24131] logger.c: -- Playing 'digits/0' (language 'en')
Sep 5 23:30:10 DEBUG[20468] chan_iax2.c: Immediately destroying 1, having received hangup
Sep 5 23:30:10 DEBUG[24131] app_voicemail.c: Hang up during prefile playback
Sep 5 23:30:10 VERBOSE[24131] logger.c: == Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'IAX2/teliax-sb-1' in macro 'vm'
Sep 5 23:30:10 VERBOSE[24131] logger.c: == Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'IAX2/teliax-sb-1' in macro 'exten-vm'
Sep 5 23:30:10 VERBOSE[24131] logger.c: == Spawn extension (macro-vm, s-NOANSWER, 2) exited non-zero on 'IAX2/teliax-sb-1'
Sep 5 23:30:10 DEBUG[24131] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record.
Sep 5 23:30:10 DEBUG[24131] 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 ('2006-09-05 23:29:32','\"PCS Phone CO\" <3035212488>','3035212488','1000','ivr-10', 'IAX2/teliax-sb-1','SIP/1000-086660b8','VoiceMail','1000@default|u',38,38,'ANSWERED',3,'')
Sep 5 23:30:10 DEBUG[24131] chan_iax2.c: We're hanging up IAX2/teliax-sb-1 now...
Sep 5 23:30:10 DEBUG[24131] chan_iax2.c: Really destroying IAX2/teliax-sb-1 now...
Sep 5 23:30:10 VERBOSE[24131] logger.c: -- Hungup 'IAX2/teliax-sb-1'