Feb 2 17:43:28 DEBUG[2949] chan_sip.c: Auto destroying call 'c0a8017a-13c4-45bfb077-209e-5ed7'
Feb 2 17:43:29 DEBUG[2949] chan_sip.c: Setting NAT on RTP to 0
Feb 2 17:43:29 DEBUG[2949] chan_sip.c: Stopping retransmission on '689730-c0a8010a-13c4-16dcd-594f2ff-6e33@192.168.1.123' of Response 1: Match Found
Feb 2 17:43:29 DEBUG[2949] chan_sip.c: Setting NAT on RTP to 0
Feb 2 17:43:29 DEBUG[2949] chan_sip.c: Checking SIP call limits for device 9
Feb 2 17:43:29 DEBUG[2949] chan_sip.c: build_route: Contact hop:
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "Catch-All DID Match - Found 111 - You probably want a DID for this.") in new stack
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing Goto("SIP/9-08dd87b8", "ext-did|s|1") in new stack
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Goto (ext-did,s,1)
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "FROM_DID=s") in new stack
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing Gosub("SIP/9-08dd87b8", "app-blacklist-check|s|1") in new stack
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing LookupBlacklist("SIP/9-08dd87b8", "") in new stack
Feb 2 17:43:29 DEBUG[24465] db.c: Unable to find key '9' in family 'blacklist'
Feb 2 17:43:29 DEBUG[24465] db.c: Unable to find key 'device' in family 'blacklist'
Feb 2 17:43:29 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "0?blacklisted") in new stack
Feb 2 17:43:29 DEBUG[24465] pbx.c: Not taking any branch
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing Return("SIP/9-08dd87b8", "") in new stack
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing Goto("SIP/9-08dd87b8", "ivr-3|s|1") in new stack
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Goto (ivr-3,s,1)
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "LOOPCOUNT=0") in new stack
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "__DIR-CONTEXT=default") in new stack
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing Answer("SIP/9-08dd87b8", "") in new stack
Feb 2 17:43:29 VERBOSE[24465] logger.c: -- Executing Wait("SIP/9-08dd87b8", "1") in new stack
Feb 2 17:43:29 DEBUG[2949] chan_sip.c: Stopping retransmission on '689730-c0a8010a-13c4-16dcd-594f2ff-6e33@192.168.1.123' of Response 2: Match Found
Feb 2 17:43:30 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "TIMEOUT(digit)=3") in new stack
Feb 2 17:43:30 VERBOSE[24465] logger.c: -- Digit timeout set to 3
Feb 2 17:43:30 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "TIMEOUT(response)=10") in new stack
Feb 2 17:43:30 VERBOSE[24465] logger.c: -- Response timeout set to 10
Feb 2 17:43:30 VERBOSE[24465] logger.c: -- Executing BackGround("SIP/9-08dd87b8", "redi3") in new stack
Feb 2 17:43:30 DEBUG[24465] channel.c: Scheduling timer at 160 sample intervals
Feb 2 17:43:30 VERBOSE[24465] logger.c: -- Playing 'redi3' (language 'en')
Feb 2 17:43:33 NOTICE[2949] chan_sip.c: Registration from '' failed for '192.168.1.10' - Username/auth name mismatch
Feb 2 17:43:33 NOTICE[2949] chan_sip.c: Registration from '' failed for '192.168.1.10' - Username/auth name mismatch
Feb 2 17:43:33 NOTICE[2949] chan_sip.c: Registration from '' failed for '192.168.1.10' - Username/auth name mismatch
Feb 2 17:43:35 DEBUG[2949] chan_sip.c: Stopping retransmission on '14a7bf4615c1230e4e21d7b42529bd26@192.168.1.123' of Request 102: Match Found
Feb 2 17:43:35 DEBUG[2949] chan_sip.c: Stopping retransmission on '5935c9e4544879c22105c856695d2ab2@192.168.1.123' of Request 102: Match Found
Feb 2 17:43:36 DEBUG[2949] chan_sip.c: Stopping retransmission on '72b835b97692246934ec7421618381ac@192.168.1.123' of Request 102: Match Found
Feb 2 17:43:38 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:38 DEBUG[24465] pbx.c: Oooh, got something to jump out with ('1')!
Feb 2 17:43:39 VERBOSE[24465] logger.c: == CDR updated on SIP/9-08dd87b8
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing DBdel("SIP/9-08dd87b8", "") in new stack
Feb 2 17:43:39 DEBUG[24465] app_db.c: Ignoring, no parameters
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "__NODEST=") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Goto("SIP/9-08dd87b8", "ext-local|3002|1") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Goto (ext-local,3002,1)
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Macro("SIP/9-08dd87b8", "exten-vm|3002|3002") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Macro("SIP/9-08dd87b8", "user-callerid") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Function result is 'device'
Feb 2 17:43:39 DEBUG[24465] pbx.c: Function result is '9'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "user-callerid: device 9") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "0?report") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Not taking any branch
Feb 2 17:43:39 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "0?start") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Not taking any branch
Feb 2 17:43:39 DEBUG[24465] pbx.c: Function result is '9'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "REALCALLERIDNUM=9") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "REALCALLERIDNUM is 9") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Function result is '9'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "AMPUSER=9") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Function result is '9'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "AMPUSERCIDNAME=9") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Expression result is '1'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "1?report") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Goto (macro-user-callerid,s,11)
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "TTL: ARG1: 3002") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "0?continue") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Not taking any branch
Feb 2 17:43:39 DEBUG[24465] pbx.c: Expression result is '1'
Feb 2 17:43:39 DEBUG[24465] pbx.c: Expression result is '-1'
Feb 2 17:43:39 DEBUG[24465] pbx.c: Function result is '64'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "_TTL=64") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Expression result is '1'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "1?continue") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Goto (macro-user-callerid,s,21)
Feb 2 17:43:39 DEBUG[24465] pbx.c: Function result is '"device" <9>'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "Using CallerID "device" <9>") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "FROMCONTEXT=exten-vm") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "VMBOX=3002") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "EXTTOCALL=3002") in new stack
Feb 2 17:43:39 DEBUG[24465] db.c: Unable to find key '3002' in family 'CFU'
Feb 2 17:43:39 DEBUG[24465] func_db.c: DB: CFU/3002 not found in database.
Feb 2 17:43:39 DEBUG[24465] pbx.c: Function result is ''
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "CFUEXT=") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Expression result is '1'
Feb 2 17:43:39 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:39 DEBUG[24465] pbx.c: Expression result is '1'
Feb 2 17:43:39 DEBUG[24465] pbx.c: Function result is '15'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "RT=15") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing Macro("SIP/9-08dd87b8", "record-enable|3002|IN") in new stack
Feb 2 17:43:39 DEBUG[24465] pbx.c: Function result is '0'
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "0 > 0?2:4") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Goto (macro-record-enable,s,4)
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Executing DeadAGI("SIP/9-08dd87b8", "recordingcheck|20070202-174339|1170456209.178") in new stack
Feb 2 17:43:39 VERBOSE[24465] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck
Feb 2 17:43:40 VERBOSE[24465] logger.c: recordingcheck|20070202-174339|1170456209.178: Inbound recording not enabled
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- AGI Script recordingcheck completed, returning 0
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "No recording needed") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing Macro("SIP/9-08dd87b8", "dial|15|tr|3002") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing DeadAGI("SIP/9-08dd87b8", "dialparties.agi") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi
Feb 2 17:43:40 VERBOSE[24465] logger.c: dialparties.agi: Starting New Dialparties.agi
Feb 2 17:43:40 VERBOSE[24465] logger.c: dialparties.agi: priority is 1
Feb 2 17:43:40 VERBOSE[24465] logger.c: dialparties.agi: Caller ID name is 'device' number is '9'
Feb 2 17:43:40 VERBOSE[24465] logger.c: dialparties.agi: Methodology of ring is 'none'
Feb 2 17:43:40 VERBOSE[24465] logger.c: > dialparties.agi: USE_CONFIRMATION: 'FALSE'
Feb 2 17:43:40 VERBOSE[24465] logger.c: > dialparties.agi: RINGGROUP_INDEX: ''
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- dialparties.agi: Added extension 3002 to extension map
Feb 2 17:43:40 DEBUG[24465] db.c: Unable to find key '3002' in family 'CF'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- dialparties.agi: Extension 3002 cf is disabled
Feb 2 17:43:40 DEBUG[24465] db.c: Unable to find key '3002' in family 'DND'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- dialparties.agi: Extension 3002 do not disturb is disabled
Feb 2 17:43:40 DEBUG[24465] db.c: Unable to find key '3002' in family 'CFB'
Feb 2 17:43:40 DEBUG[24465] db.c: Unable to find key '3002' in family 'CFU'
Feb 2 17:43:40 VERBOSE[24465] logger.c: > dialparties.agi: extnum: 3002
Feb 2 17:43:40 VERBOSE[24465] logger.c: > dialparties.agi: exthascw: 1
Feb 2 17:43:40 VERBOSE[24465] logger.c: > dialparties.agi: exthascfb: 0
Feb 2 17:43:40 VERBOSE[24465] logger.c: > dialparties.agi: extcfb:
Feb 2 17:43:40 VERBOSE[24465] logger.c: > dialparties.agi: exthascfu: 0
Feb 2 17:43:40 VERBOSE[24465] logger.c: > dialparties.agi: extcfu:
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- dialparties.agi: dbset CALLTRACE/3002 to 9
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- AGI Script dialparties.agi completed, returning 0
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing Dial("SIP/9-08dd87b8", "IAX2/3002|15|tr") in new stack
Feb 2 17:43:40 NOTICE[24465] app_dial.c: Unable to create channel of type 'IAX2' (cause 3 - No route to destination)
Feb 2 17:43:40 VERBOSE[24465] logger.c: == Everyone is busy/congested at this time (1:0/0/1)
Feb 2 17:43:40 DEBUG[24465] app_dial.c: Exiting with DIALSTATUS=CHANUNAVAIL.
Feb 2 17:43:40 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:40 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:40 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing GosubIf("SIP/9-08dd87b8", "0?docfu|1") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "Voicemail is 3002") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "0?s-CHANUNAVAIL|1") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Not taking any branch
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "Sending to Voicemail box 3002") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing Macro("SIP/9-08dd87b8", "vm|3002|CHANUNAVAIL") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing Macro("SIP/9-08dd87b8", "user-callerid|SKIPTTL") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Function result is 'device'
Feb 2 17:43:40 DEBUG[24465] pbx.c: Function result is '9'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "user-callerid: device 9") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "0?report") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Not taking any branch
Feb 2 17:43:40 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "0?start") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Not taking any branch
Feb 2 17:43:40 DEBUG[24465] pbx.c: Function result is '9'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "REALCALLERIDNUM=9") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "REALCALLERIDNUM is 9") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Function result is '9'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "AMPUSER=9") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Function result is '9'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "AMPUSERCIDNAME=9") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Expression result is '1'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "1?report") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Goto (macro-user-callerid,s,11)
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "TTL: 64 ARG1: SKIPTTL") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Expression result is '1'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "1?continue") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Goto (macro-user-callerid,s,21)
Feb 2 17:43:40 DEBUG[24465] pbx.c: Function result is '"device" <9>'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "Using CallerID "device" <9>") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:40 DEBUG[24465] pbx.c: Function result is ''
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "VMGAIN=") in new stack
Feb 2 17:43:40 WARNING[24465] func_db.c: DB requires an argument, DB(/)
Feb 2 17:43:40 DEBUG[24465] pbx.c: Function result is ''
Feb 2 17:43:40 DEBUG[24465] pbx.c: Expression result is '1'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "1?s-CHANUNAVAIL|1") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Goto (macro-vm,s-CHANUNAVAIL,1)
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing Macro("SIP/9-08dd87b8", "get-vmcontext|3002") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Function result is 'default'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing Set("SIP/9-08dd87b8", "VMCONTEXT=default") in new stack
Feb 2 17:43:40 DEBUG[24465] pbx.c: Expression result is '0'
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing GotoIf("SIP/9-08dd87b8", "0?200:300") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Goto (macro-get-vmcontext,s,300)
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing NoOp("SIP/9-08dd87b8", "") in new stack
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Executing VoiceMail("SIP/9-08dd87b8", "3002@default|u") in new stack
Feb 2 17:43:40 DEBUG[24465] app_voicemail.c: /var/spool/asterisk/voicemail/default/3002/unavail doesn't exist, doing what we can
Feb 2 17:43:40 DEBUG[24465] channel.c: Scheduling timer at 160 sample intervals
Feb 2 17:43:40 VERBOSE[24465] logger.c: -- Playing 'vm-theperson' (language 'en')
Feb 2 17:43:41 DEBUG[24465] channel.c: Scheduling timer at 2 sample intervals
Feb 2 17:43:41 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:41 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:41 DEBUG[24465] channel.c: Scheduling timer at 160 sample intervals
Feb 2 17:43:41 VERBOSE[24465] logger.c: -- Playing 'digits/3' (language 'en')
Feb 2 17:43:42 DEBUG[24465] channel.c: Scheduling timer at 61 sample intervals
Feb 2 17:43:42 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:42 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:42 DEBUG[24465] channel.c: Scheduling timer at 160 sample intervals
Feb 2 17:43:42 VERBOSE[24465] logger.c: -- Playing 'digits/0' (language 'en')
Feb 2 17:43:43 DEBUG[24465] channel.c: Scheduling timer at 102 sample intervals
Feb 2 17:43:43 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:43 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:43 DEBUG[24465] channel.c: Scheduling timer at 160 sample intervals
Feb 2 17:43:43 VERBOSE[24465] logger.c: -- Playing 'digits/0' (language 'en')
Feb 2 17:43:44 DEBUG[24465] channel.c: Scheduling timer at 102 sample intervals
Feb 2 17:43:44 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:44 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:44 DEBUG[24465] channel.c: Scheduling timer at 160 sample intervals
Feb 2 17:43:44 VERBOSE[24465] logger.c: -- Playing 'digits/2' (language 'en')
Feb 2 17:43:44 DEBUG[24465] channel.c: Scheduling timer at 128 sample intervals
Feb 2 17:43:44 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:44 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:44 DEBUG[24465] channel.c: Scheduling timer at 160 sample intervals
Feb 2 17:43:44 VERBOSE[24465] logger.c: -- Playing 'vm-isunavail' (language 'en')
Feb 2 17:43:46 DEBUG[24465] channel.c: Scheduling timer at 50 sample intervals
Feb 2 17:43:46 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:46 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:46 DEBUG[24465] channel.c: Scheduling timer at 160 sample intervals
Feb 2 17:43:46 VERBOSE[24465] logger.c: -- Playing 'vm-intro' (language 'en')
Feb 2 17:43:48 DEBUG[2949] chan_sip.c: Auto destroying call 'c0a8010a-13c4-16dd1-59502c7-7b4'
Feb 2 17:43:48 DEBUG[2949] chan_sip.c: Auto destroying call 'c0a8010a-13c4-16dd1-595031c-cd9'
Feb 2 17:43:48 DEBUG[2949] chan_sip.c: Auto destroying call 'c0a8010a-13c4-16dd1-5950376-2eaa'
Feb 2 17:43:48 DEBUG[2949] chan_sip.c: Auto destroying call 'c0a8010a-13c4-16dd1-5950268-70ab'
Feb 2 17:43:51 DEBUG[24465] channel.c: Scheduling timer at 6 sample intervals
Feb 2 17:43:51 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:51 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:51 DEBUG[24465] app.c: Locked path '/var/spool/asterisk/voicemail/default/3002/INBOX'
Feb 2 17:43:51 DEBUG[24465] app.c: Unlocked path '/var/spool/asterisk/voicemail/default/3002/INBOX'
Feb 2 17:43:51 DEBUG[24465] channel.c: Scheduling timer at 160 sample intervals
Feb 2 17:43:51 VERBOSE[24465] logger.c: -- Playing 'beep' (language 'en')
Feb 2 17:43:51 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:51 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:43:51 VERBOSE[24465] logger.c: -- Recording the message
Feb 2 17:43:51 DEBUG[24465] app.c: play_and_record: , /var/spool/asterisk/voicemail/default/3002/tmp/GEb5Hg, 'wav49|wav'
Feb 2 17:43:51 DEBUG[24465] app.c: Recording Formats: sfmts=wav49
Feb 2 17:43:51 VERBOSE[24465] logger.c: -- x=0, open writing: /var/spool/asterisk/voicemail/default/3002/tmp/GEb5Hg format: wav49, 0x8db8e88
Feb 2 17:43:51 VERBOSE[24465] logger.c: -- x=1, open writing: /var/spool/asterisk/voicemail/default/3002/tmp/GEb5Hg format: wav, 0x8da8000
Feb 2 17:43:51 DEBUG[24465] channel.c: Scheduling timer at 160 sample intervals
Feb 2 17:43:54 DEBUG[24465] channel.c: Generator got voice, switching to phase locked mode
Feb 2 17:43:54 DEBUG[24465] channel.c: Scheduling timer at 0 sample intervals
Feb 2 17:44:08 DEBUG[2949] chan_sip.c: Auto destroying call 'c0a8017a-13c4-45bfb077-209e-5ed7'
Feb 2 17:44:20 DEBUG[2949] chan_sip.c: Stopping retransmission on '4335cdee0246a44f0cf282d903b12409@192.168.1.123' of Request 102: Match Found
Feb 2 17:44:23 NOTICE[2949] chan_sip.c: Registration from '' failed for '192.168.1.10' - Username/auth name mismatch
Feb 2 17:44:23 NOTICE[2949] chan_sip.c: Registration from '' failed for '192.168.1.10' - Username/auth name mismatch
Feb 2 17:44:23 NOTICE[2949] chan_sip.c: Registration from '' failed for '192.168.1.10' - Username/auth name mismatch
Feb 2 17:44:23 NOTICE[2949] chan_sip.c: Registration from '' failed for '192.168.1.10' - Username/auth name mismatch