My sip show peers: ========================================================================= Connected to Asterisk 1.2.14 currently running on prxyafr (pid = 15232) Verbosity was 0 and is now 12 prxyafr*CLI> sip show peers Name/username Host Dyn Nat ACL Port Status 115 (Unspecified) D N 0 UNKNOWN 114 (Unspecified) D N 0 UNKNOWN 113 (Unspecified) D N 0 UNKNOWN 112 (Unspecified) D N 0 UNKNOWN 111 (Unspecified) D N 0 UNKNOWN 110 (Unspecified) D N 0 UNKNOWN 109 (Unspecified) D N 0 UNKNOWN 108 (Unspecified) D N 0 UNKNOWN 107 (Unspecified) D N 0 UNKNOWN 106/106 200.93.220.7 D N 5060 OK (282 ms) 105/105 200.58.211.225 D N 60089 OK (113 ms) 104 (Unspecified) D N 0 UNKNOWN 103 (Unspecified) D N 0 UNKNOWN 102 (Unspecified) D N 0 UNKNOWN 101 (Unspecified) D N 0 UNKNOWN 100 (Unspecified) D N 0 UNKNOWN 16 sip peers [2 online , 14 offline] This is the log, first calling to a non registered extension (101): Feb 9 08:44:42 DEBUG[15242] chan_sip.c: Stopping retransmission on '15eca8c339414a4b1af1e1c75ed2f97e@190.24.227.62' of Request 102: Match Found Feb 9 08:44:44 DEBUG[15242] chan_sip.c: Stopping retransmission on '581d196749530c0a0aca8bd549f4e4e4@190.24.227.62' of Request 102: Match Found Feb 9 08:44:49 DEBUG[15242] chan_sip.c: Setting NAT on RTP to 524288 Feb 9 08:44:49 DEBUG[15242] chan_sip.c: Stopping retransmission on '3046286146@200.93.220.7' of Response 1: Match Found Feb 9 08:44:49 DEBUG[15242] chan_sip.c: Setting NAT on RTP to 524288 Feb 9 08:44:49 DEBUG[15242] chan_sip.c: Checking SIP call limits for device 106 Feb 9 08:44:49 DEBUG[15242] chan_sip.c: build_route: Contact hop: Guillermo Salas M Feb 9 08:44:49 DEBUG[15237] channel.c: Avoiding initial deadlock for 'SIP/106-08176ae8' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Macro("SIP/106-08176ae8", "exten-vm|101|101") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Macro("SIP/106-08176ae8", "user-callerid") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is 'device' Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '106' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "user-callerid: device 106") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "0?report") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Not taking any branch Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "0?start") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Not taking any branch Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '106' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "REALCALLERIDNUM=106") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "REALCALLERIDNUM is 106") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '106' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "AMPUSER=106") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is 'Extension 106' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "AMPUSERCIDNAME=Extension 106") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "0?report") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Not taking any branch Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "CALLERID(all)=Extension 106 <106>") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '106' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "REALCALLERIDNUM=106") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "TTL: ARG1: 101") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "0?continue") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Not taking any branch Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '1' Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '-1' Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '64' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "_TTL=64") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '1' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "1?continue") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Goto (macro-user-callerid,s,21) Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '"Extension 106" <106>' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "Using CallerID "Extension 106" <106>") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "FROMCONTEXT=exten-vm") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "VMBOX=101") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "EXTTOCALL=101") in new stack Feb 9 08:44:49 DEBUG[15306] db.c: Unable to find key '101' in family 'CFU' Feb 9 08:44:49 DEBUG[15306] func_db.c: DB: CFU/101 not found in database. Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "CFUEXT=") in new stack Feb 9 08:44:49 DEBUG[15306] db.c: Unable to find key '101' in family 'CFB' Feb 9 08:44:49 DEBUG[15306] func_db.c: DB: CFB/101 not found in database. Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "CFBEXT=") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '1' Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '1' Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '15' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "RT=15") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Macro("SIP/106-08176ae8", "record-enable|101|IN") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '0' Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "0?2:4") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Goto (macro-record-enable,s,4) Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing DeadAGI("SIP/106-08176ae8", "recordingcheck|20070209-084449|1171028689.2") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Launched AGI Script /usr/share/asterisk/agi-bin/recordingcheck Feb 9 08:44:49 VERBOSE[15306] logger.c: -- AGI Script recordingcheck completed, returning 0 Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "No recording needed") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Macro("SIP/106-08176ae8", "dial|15|tr|101") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing DeadAGI("SIP/106-08176ae8", "dialparties.agi") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Launched AGI Script /usr/share/asterisk/agi-bin/dialparties.agi Feb 9 08:44:49 VERBOSE[15306] logger.c: -- AGI Script dialparties.agi completed, returning 0 Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "Returned from dialparties with no extensions to call") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "DIALSTATUS is ") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GosubIf("SIP/106-08176ae8", "0?docfu|1") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GosubIf("SIP/106-08176ae8", "0?docfb|1") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "Voicemail is 101") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "0?s-|1") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Not taking any branch Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "Sending to Voicemail box 101") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Macro("SIP/106-08176ae8", "vm|101|") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Macro("SIP/106-08176ae8", "user-callerid|SKIPTTL") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is 'Extension 106' Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '106' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "user-callerid: Extension 106 106") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "0?report") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Not taking any branch Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '1' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "1?start") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Goto (macro-user-callerid,s,5) Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "REALCALLERIDNUM is 106") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '106' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "AMPUSER=106") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is 'Extension 106' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "AMPUSERCIDNAME=Extension 106") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "0?report") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Not taking any branch Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "CALLERID(all)=Extension 106 <106>") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '106' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "REALCALLERIDNUM=106") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "TTL: 64 ARG1: SKIPTTL") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '1' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "1?continue") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Goto (macro-user-callerid,s,21) Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '"Extension 106" <106>' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "Using CallerID "Extension 106" <106>") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "VMGAIN=") in new stack Feb 9 08:44:49 WARNING[15306] func_db.c: DB requires an argument, DB(/) Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is '' Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '1' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "1?s-|1") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Goto (macro-vm,s-,1) Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Macro("SIP/106-08176ae8", "get-vmcontext|101") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Function result is 'default' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing Set("SIP/106-08176ae8", "VMCONTEXT=default") in new stack Feb 9 08:44:49 DEBUG[15306] pbx.c: Expression result is '0' Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing GotoIf("SIP/106-08176ae8", "0?200:300") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Goto (macro-get-vmcontext,s,300) Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing NoOp("SIP/106-08176ae8", "") in new stack Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Executing VoiceMail("SIP/106-08176ae8", "101@default|u") in new stack Feb 9 08:44:49 DEBUG[15237] channel.c: Avoiding initial deadlock for 'SIP/106-08176ae8' Feb 9 08:44:49 DEBUG[15306] app_voicemail.c: /var/spool/asterisk/voicemail/default/101/unavail doesn't exist, doing what we can Feb 9 08:44:49 DEBUG[15306] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:44:49 VERBOSE[15306] logger.c: -- Playing 'vm-theperson' (language 'es') Feb 9 08:44:49 DEBUG[15242] chan_sip.c: Stopping retransmission on '3046286146@200.93.220.7' of Response 2: Match Found Feb 9 08:44:50 DEBUG[15306] chan_sip.c: Oooh, format changed to 8 Feb 9 08:44:51 DEBUG[15306] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:44:51 DEBUG[15306] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:44:51 DEBUG[15306] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:44:51 VERBOSE[15306] logger.c: -- Playing 'digits/1' (language 'es') Feb 9 08:44:51 DEBUG[15306] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:44:51 DEBUG[15306] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:44:51 DEBUG[15306] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:44:51 VERBOSE[15306] logger.c: -- Playing 'digits/0' (language 'es') Feb 9 08:44:52 DEBUG[15306] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:44:52 DEBUG[15306] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:44:52 DEBUG[15306] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:44:52 VERBOSE[15306] logger.c: -- Playing 'digits/1' (language 'es') Feb 9 08:44:53 DEBUG[15306] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:44:53 DEBUG[15306] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:44:53 DEBUG[15306] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:44:53 VERBOSE[15306] logger.c: -- Playing 'vm-isunavail' (language 'es') Feb 9 08:44:54 DEBUG[15306] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:44:54 DEBUG[15306] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:44:54 DEBUG[15306] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:44:54 VERBOSE[15306] logger.c: -- Playing 'vm-intro' (language 'es') Feb 9 08:44:56 VERBOSE[15306] logger.c: == Spawn extension (macro-vm, s-, 2) exited non-zero on 'SIP/106-08176ae8' in macro 'vm' Feb 9 08:44:56 VERBOSE[15306] logger.c: == Spawn extension (macro-vm, s-, 2) exited non-zero on 'SIP/106-08176ae8' in macro 'exten-vm' Feb 9 08:44:56 VERBOSE[15306] logger.c: == Spawn extension (macro-vm, s-, 2) exited non-zero on 'SIP/106-08176ae8' Feb 9 08:44:56 DEBUG[15306] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:44:56 DEBUG[15306] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. Feb 9 08:44:56 DEBUG[15306] 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-02-09 08:44:49','\"Extension 106\" <106>','106','101','from-internal', 'SIP/106-08176ae8','','VoiceMail','101@default|u',7,7,'ANSWERED',3,'') Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '"Extension 106" <106>' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '106' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '101' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is 'from-internal' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is 'SIP/106-08176ae8' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '(null)' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is 'VoiceMail' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '101@default|u' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '2007-02-09 08:44:49' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '2007-02-09 08:44:49' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '2007-02-09 08:44:56' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '7' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '7' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is 'ANSWERED' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is 'DOCUMENTATION' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '(null)' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '1171028689.2' Feb 9 08:44:56 DEBUG[15306] pbx.c: Function result is '(null)' Feb 9 08:44:56 DEBUG[15306] chan_sip.c: update_call_counter(106) - decrement call limit counter Now when I call to another extension that is registered (105) takes me to the voice message: Feb 9 08:45:04 DEBUG[15242] chan_sip.c: Setting NAT on RTP to 524288 Feb 9 08:45:05 DEBUG[15242] chan_sip.c: Stopping retransmission on '637586342@200.93.220.7' of Response 1: Match Found Feb 9 08:45:05 DEBUG[15242] chan_sip.c: Setting NAT on RTP to 524288 Feb 9 08:45:05 DEBUG[15242] chan_sip.c: Checking SIP call limits for device 106 Feb 9 08:45:05 DEBUG[15242] chan_sip.c: build_route: Contact hop: Guillermo Salas M Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Macro("SIP/106-081cc738", "exten-vm|105|105") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Macro("SIP/106-081cc738", "user-callerid") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is 'device' Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '106' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "user-callerid: device 106") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "0?report") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Not taking any branch Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "0?start") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Not taking any branch Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '106' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "REALCALLERIDNUM=106") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "REALCALLERIDNUM is 106") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '106' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "AMPUSER=106") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is 'Extension 106' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "AMPUSERCIDNAME=Extension 106") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "0?report") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Not taking any branch Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "CALLERID(all)=Extension 106 <106>") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '106' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "REALCALLERIDNUM=106") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "TTL: ARG1: 105") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "0?continue") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Not taking any branch Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '1' Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '-1' Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '64' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "_TTL=64") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '1' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "1?continue") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Goto (macro-user-callerid,s,21) Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '"Extension 106" <106>' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "Using CallerID "Extension 106" <106>") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "FROMCONTEXT=exten-vm") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "VMBOX=105") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "EXTTOCALL=105") in new stack Feb 9 08:45:05 DEBUG[15312] db.c: Unable to find key '105' in family 'CFU' Feb 9 08:45:05 DEBUG[15312] func_db.c: DB: CFU/105 not found in database. Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "CFUEXT=") in new stack Feb 9 08:45:05 DEBUG[15312] db.c: Unable to find key '105' in family 'CFB' Feb 9 08:45:05 DEBUG[15312] func_db.c: DB: CFB/105 not found in database. Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "CFBEXT=") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '1' Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '1' Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '15' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "RT=15") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Macro("SIP/106-081cc738", "record-enable|105|IN") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '0' Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "0?2:4") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Goto (macro-record-enable,s,4) Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing DeadAGI("SIP/106-081cc738", "recordingcheck|20070209-084505|1171028705.3") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Launched AGI Script /usr/share/asterisk/agi-bin/recordingcheck Feb 9 08:45:05 VERBOSE[15312] logger.c: -- AGI Script recordingcheck completed, returning 0 Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "No recording needed") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Macro("SIP/106-081cc738", "dial|15|tr|105") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing DeadAGI("SIP/106-081cc738", "dialparties.agi") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Launched AGI Script /usr/share/asterisk/agi-bin/dialparties.agi Feb 9 08:45:05 VERBOSE[15312] logger.c: -- AGI Script dialparties.agi completed, returning 0 Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "Returned from dialparties with no extensions to call") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "DIALSTATUS is ") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GosubIf("SIP/106-081cc738", "0?docfu|1") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GosubIf("SIP/106-081cc738", "0?docfb|1") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "Voicemail is 105") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "0?s-|1") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Not taking any branch Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "Sending to Voicemail box 105") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Macro("SIP/106-081cc738", "vm|105|") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Macro("SIP/106-081cc738", "user-callerid|SKIPTTL") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is 'Extension 106' Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '106' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "user-callerid: Extension 106 106") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "0?report") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Not taking any branch Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '1' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "1?start") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Goto (macro-user-callerid,s,5) Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "REALCALLERIDNUM is 106") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '106' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "AMPUSER=106") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is 'Extension 106' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "AMPUSERCIDNAME=Extension 106") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "0?report") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Not taking any branch Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "CALLERID(all)=Extension 106 <106>") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '106' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "REALCALLERIDNUM=106") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "TTL: 64 ARG1: SKIPTTL") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '1' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "1?continue") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Goto (macro-user-callerid,s,21) Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '"Extension 106" <106>' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing NoOp("SIP/106-081cc738", "Using CallerID "Extension 106" <106>") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '0' Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "VMGAIN=") in new stack Feb 9 08:45:05 WARNING[15312] func_db.c: DB requires an argument, DB(/) Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '' Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '1' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "1?s-|1") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Goto (macro-vm,s-,1) Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Macro("SIP/106-081cc738", "get-vmcontext|105") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Function result is '' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "VMCONTEXT=") in new stack Feb 9 08:45:05 DEBUG[15312] pbx.c: Expression result is '1' Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing GotoIf("SIP/106-081cc738", "1?200:300") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Goto (macro-get-vmcontext,s,200) Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing Set("SIP/106-081cc738", "VMCONTEXT=default") in new stack Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Executing VoiceMail("SIP/106-081cc738", "105@default|u") in new stack Feb 9 08:45:05 DEBUG[15237] channel.c: Avoiding initial deadlock for 'SIP/106-081cc738' Feb 9 08:45:05 DEBUG[15312] app_voicemail.c: /var/spool/asterisk/voicemail/default/105/unavail doesn't exist, doing what we can Feb 9 08:45:05 DEBUG[15312] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:45:05 VERBOSE[15312] logger.c: -- Playing 'vm-theperson' (language 'es') Feb 9 08:45:05 DEBUG[15242] chan_sip.c: Stopping retransmission on '637586342@200.93.220.7' of Response 2: Match Found Feb 9 08:45:05 DEBUG[15312] chan_sip.c: Oooh, format changed to 8 Feb 9 08:45:06 DEBUG[15312] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:45:06 DEBUG[15312] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:45:06 DEBUG[15312] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:45:06 VERBOSE[15312] logger.c: -- Playing 'digits/1' (language 'es') Feb 9 08:45:07 DEBUG[15312] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:45:07 DEBUG[15312] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:45:07 DEBUG[15312] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:45:07 VERBOSE[15312] logger.c: -- Playing 'digits/0' (language 'es') Feb 9 08:45:08 DEBUG[15312] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:45:08 DEBUG[15312] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:45:08 DEBUG[15312] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:45:08 VERBOSE[15312] logger.c: -- Playing 'digits/5' (language 'es') Feb 9 08:45:09 DEBUG[15312] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:45:09 DEBUG[15312] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:45:09 DEBUG[15312] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:45:09 VERBOSE[15312] logger.c: -- Playing 'vm-isunavail' (language 'es') Feb 9 08:45:10 DEBUG[15312] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:45:10 DEBUG[15312] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:45:10 DEBUG[15312] channel.c: Scheduling timer at 160 sample intervals Feb 9 08:45:10 VERBOSE[15312] logger.c: -- Playing 'vm-intro' (language 'es') Feb 9 08:45:15 VERBOSE[15312] logger.c: == Spawn extension (macro-vm, s-, 2) exited non-zero on 'SIP/106-081cc738' in macro 'vm' Feb 9 08:45:15 VERBOSE[15312] logger.c: == Spawn extension (macro-vm, s-, 2) exited non-zero on 'SIP/106-081cc738' in macro 'exten-vm' Feb 9 08:45:15 VERBOSE[15312] logger.c: == Spawn extension (macro-vm, s-, 2) exited non-zero on 'SIP/106-081cc738' Feb 9 08:45:15 DEBUG[15312] channel.c: Scheduling timer at 0 sample intervals Feb 9 08:45:15 DEBUG[15312] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. Feb 9 08:45:15 DEBUG[15312] 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-02-09 08:45:05','\"Extension 106\" <106>','106','105','from-internal', 'SIP/106-081cc738','','VoiceMail','105@default|u',10,10,'ANSWERED',3,'') Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '"Extension 106" <106>' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '106' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '105' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is 'from-internal' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is 'SIP/106-081cc738' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '(null)' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is 'VoiceMail' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '105@default|u' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '2007-02-09 08:45:05' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '2007-02-09 08:45:05' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '2007-02-09 08:45:15' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '10' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '10' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is 'ANSWERED' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is 'DOCUMENTATION' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '(null)' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '1171028705.3' Feb 9 08:45:15 DEBUG[15312] pbx.c: Function result is '(null)' Feb 9 08:45:15 DEBUG[15312] chan_sip.c: update_call_counter(106) - decrement call limit counter Feb 9 08:45:15 DEBUG[15312] chan_sip.c: update_call_counter(106) - decrement call limit counter