Jul 24 16:04:13 VERBOSE[2924] logger.c: --- (13 headers 0 lines)Jul 24 16:04:13 VERBOSE[2924] logger.c: --- (13 headers 0 lines)--- Jul 24 16:04:13 DEBUG[2924] chan_sip.c: Stopping retransmission on '388eb6d2595c2bf014565c9f5b27d4e6@10.24.0.12' of Request 102: Match Found Jul 24 16:04:13 VERBOSE[2924] logger.c: Destroying call '388eb6d2595c2bf014565c9f5b27d4e6@10.24.0.12' Jul 24 16:04:56 DEBUG[2924] chan_sip.c: Allocating new SIP dialog for af9f628af072786e@10.24.5.10 - INVITE (With RTP) Jul 24 16:04:56 DEBUG[2924] chan_sip.c: * SIP extension value: 5 for call af9f628af072786e@10.24.5.10 Jul 24 16:04:56 DEBUG[2924] chan_sip.c: Setting NAT on RTP to 0 Jul 24 16:04:56 DEBUG[2924] chan_sip.c: Stopping retransmission on 'af9f628af072786e@10.24.5.10' of Response 29439: Match Found Jul 24 16:04:56 DEBUG[2924] chan_sip.c: Setting NAT on RTP to 0 Jul 24 16:04:56 DEBUG[2924] chan_sip.c: Checking SIP call limits for device 111 Jul 24 16:04:56 DEBUG[2924] chan_sip.c: build_route: Contact hop: Jul 24 16:04:56 DEBUG[2881] channel.c: Avoiding initial deadlock for 'SIP/111-b7ee' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Macro' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Macro("SIP/111-b7ee", "dialout-trunk|3|12488401204||") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Expression result is '1' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'GotoIf' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing GotoIf("SIP/111-b7ee", "1?3:2") in new stack Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Goto (macro-dialout-trunk,s,3) Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Macro' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Macro("SIP/111-b7ee", "user-callerid") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Expression result is '0' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'GotoIf' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing GotoIf("SIP/111-b7ee", "0?report") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Not taking any branch Jul 24 16:04:56 DEBUG[5911] pbx.c: Expression result is '0' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'GotoIf' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing GotoIf("SIP/111-b7ee", "0?start") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Not taking any branch Jul 24 16:04:56 DEBUG[5911] pbx.c: Function result is '111' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "REALCALLERIDNUM=111") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'NoOp' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing NoOp("SIP/111-b7ee", "REALCALLERIDNUM is 111") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Function result is '111' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "AMPUSER=111") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Function result is 'Patrick Synor' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "AMPUSERCIDNAME=Patrick Synor") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Expression result is '0' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'GotoIf' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing GotoIf("SIP/111-b7ee", "0?report") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Not taking any branch Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "CALLERID(all)=Patrick Synor <111>") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Function result is '"Patrick Synor" <111>' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'NoOp' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing NoOp("SIP/111-b7ee", "Using CallerID "Patrick Synor" <111>") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Function result is '111' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Macro' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Macro("SIP/111-b7ee", "record-enable|111|OUT") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Function result is '0' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'GotoIf' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing GotoIf("SIP/111-b7ee", "0 > 0?2:4") in new stack Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Goto (macro-record-enable,s,4) Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'AGI' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing AGI("SIP/111-b7ee", "recordingcheck|20060724-160456|1153771496.18") in new stack Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck Jul 24 16:04:56 DEBUG[5913] app_queue.c: Device 'SIP/111' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 24 16:04:56 VERBOSE[5911] logger.c: recordingcheck|20060724-160456|1153771496.18: Outbound recording not enabled Jul 24 16:04:56 VERBOSE[5911] logger.c: -- AGI Script recordingcheck completed, returning 0 Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'NoOp' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing NoOp("SIP/111-b7ee", "No recording needed") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Macro' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Macro("SIP/111-b7ee", "outbound-callerid|3") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Expression result is '1' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'GotoIf' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing GotoIf("SIP/111-b7ee", "1?start") in new stack Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Goto (macro-outbound-callerid,s,3) Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'NoOp' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing NoOp("SIP/111-b7ee", "REALCALLERIDNUM is 111") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Function result is '' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "USEROUTCID=") in new stack Jul 24 16:04:56 DEBUG[5911] db.c: Unable to find key '111/emergency_cid' in family 'DEVICE' Jul 24 16:04:56 DEBUG[5911] func_db.c: DB: DEVICE/111/emergency_cid not found in database. Jul 24 16:04:56 DEBUG[5911] pbx.c: Function result is '' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "EMERGENCYCID=") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "TRUNKOUTCID=") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Expression result is '1' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'GotoIf' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing GotoIf("SIP/111-b7ee", "1?trunkcid") in new stack Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Goto (macro-outbound-callerid,s,11) Jul 24 16:04:56 DEBUG[5911] pbx.c: Expression result is '1' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'GotoIf' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing GotoIf("SIP/111-b7ee", "1?usercid") in new stack Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Goto (macro-outbound-callerid,s,13) Jul 24 16:04:56 DEBUG[5911] pbx.c: Expression result is '1' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'GotoIf' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing GotoIf("SIP/111-b7ee", "1?report") in new stack Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Goto (macro-outbound-callerid,s,15) Jul 24 16:04:56 DEBUG[5911] pbx.c: Function result is '"Patrick Synor" <111>' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'NoOp' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing NoOp("SIP/111-b7ee", "CallerID set to "Patrick Synor" <111>") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "GROUP()=OUT_3") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Function result is '1' Jul 24 16:04:56 WARNING[5911] ast_expr2.fl: ast_yyerror(): syntax error: syntax error, unexpected $end, expecting TOK_MINUS or TOK_COMPL or TOK_LP or TOKEN; Input: 1 > ^ Jul 24 16:04:56 WARNING[5911] ast_expr2.fl: If you have questions, please refer to doc/README.variables in the asterisk source. Jul 24 16:04:56 DEBUG[5911] pbx.c: Expression result is '0' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'GotoIf' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing GotoIf("SIP/111-b7ee", "0?108") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Not taking any branch Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "DIAL_NUMBER=12488401204") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "DIAL_TRUNK=3") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'AGI' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing AGI("SIP/111-b7ee", "fixlocalprefix") in new stack Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix Jul 24 16:04:56 VERBOSE[5911] logger.c: -- AGI Script fixlocalprefix completed, returning 0 Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "OUTNUM=12488401204") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Function result is 'SIP/voipdiscount' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Set' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Set("SIP/111-b7ee", "custom=SIP/voipdiscount") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Expression result is '0' Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'GotoIf' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing GotoIf("SIP/111-b7ee", "0?16") in new stack Jul 24 16:04:56 DEBUG[5911] pbx.c: Not taking any branch Jul 24 16:04:56 DEBUG[5911] pbx.c: Launching 'Dial' Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Executing Dial("SIP/111-b7ee", "SIP/voipdiscount/12488401204|120|r") in new stack Jul 24 16:04:56 DEBUG[5911] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Jul 24 16:04:56 DEBUG[5911] chan_sip.c: Setting NAT on RTP to 524288 Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-14. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable MACRO_DEPTH. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-13. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable custom. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-12. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable OUTNUM. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-11. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-10. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable DIAL_TRUNK. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-9. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable DIAL_NUMBER. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-8. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-7. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable GROUP. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-6. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable MACRO_PRIORITY. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable MACRO_CONTEXT. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable MACRO_EXTEN. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable ARG1. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-outbound-callerid-s-15. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-outbound-callerid-s-13. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-outbound-callerid-s-11. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-outbound-callerid-s-7. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable TRUNKOUTCID. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-outbound-callerid-s-6. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable EMERGENCYCID. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-outbound-callerid-s-5. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable USEROUTCID. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-outbound-callerid-s-4. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable DB_RESULT. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-outbound-callerid-s-3. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-outbound-callerid-s-1. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-5. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable ARG2. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-record-enable-s-5. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-record-enable-s-4. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-record-enable-s-1. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-4. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-user-callerid-s-9. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-user-callerid-s-8. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-user-callerid-s-7. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable AMPUSERCIDNAME. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-user-callerid-s-6. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable AMPUSER. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-user-callerid-s-5. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-user-callerid-s-4. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable REALCALLERIDNUM. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-user-callerid-s-3. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-user-callerid-s-2. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-user-callerid-s-1. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-3. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-macro-dialout-trunk-s-1. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable ARG4. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable ARG3. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable STACK-from-internal-12488401204-1. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable SIPCALLID. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable SIPUSERAGENT. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable SIPDOMAIN. Jul 24 16:04:56 DEBUG[5911] channel.c: Not copying variable SIPURI. Jul 24 16:04:56 DEBUG[5911] chan_sip.c: Outgoing Call for 12488401204 Jul 24 16:04:56 VERBOSE[5911] logger.c: We're at 10.24.0.12 port 15468 Jul 24 16:04:56 VERBOSE[5911] logger.c: Adding codec 0x4 (ulaw) to SDP Jul 24 16:04:56 VERBOSE[5911] logger.c: Adding codec 0x8 (alaw) to SDP Jul 24 16:04:56 VERBOSE[5911] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jul 24 16:04:56 VERBOSE[5911] logger.c: 14 headers, 11 lines Jul 24 16:04:56 VERBOSE[5911] logger.c: Reliably Transmitting (NAT) to 194.120.0.203:5060: INVITE sip:12488401204@sip.sipdiscount.com SIP/2.0 Via: SIP/2.0/UDP 10.24.0.12:5060;branch=z9hG4bK0e3e9ffa;rport From: "Patrick Synor" ;tag=as3b3dc4b6 To: Contact: Call-ID: 228596a67b1b217239b8535e5d7f6d5d@sipdiscount.com CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Remote-Party-ID: "Patrick Synor" ;privacy=off;screen=no Date: Mon, 24 Jul 2006 20:04:56 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 234 v=0 o=root 2849 2849 IN IP4 10.24.0.12 s=session c=IN IP4 10.24.0.12 t=0 0 m=audio 15468 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jul 24 16:04:56 VERBOSE[5911] logger.c: -- Called voipdiscount/12488401204 Jul 24 16:04:57 VERBOSE[2924] logger.c: <-- SIP read from 194.120.0.203:5060: SIP/2.0 400 Bad request Via: SIP/2.0/UDP 10.24.0.12:5060;branch=z9hG4bK0e3e9ffa;rport To: Contact: sip:12488401204@194.120.0.203:5060 Call-ID: 228596a67b1b217239b8535e5d7f6d5d@sipdiscount.com CSeq: 102 INVITE User-Agent: (Very nice Sip Registrar Server) Allow: ACK,BYE,CANCEL,INVITE,REGISTER,OPTIONS Content-Length: 0 Jul 24 16:04:57 VERBOSE[2924] logger.c: --- (9 headers 0 lines)Jul 24 16:04:57 VERBOSE[2924] logger.c: --- (9 headers 0 lines)--- Jul 24 16:04:57 DEBUG[2924] chan_sip.c: Acked pending invite 102 Jul 24 16:04:57 DEBUG[2924] chan_sip.c: Stopping retransmission on '228596a67b1b217239b8535e5d7f6d5d@sipdiscount.com' of Request 102: Match Found Jul 24 16:04:57 VERBOSE[2924] logger.c: -- Got SIP response 400 "Bad request" back from 194.120.0.203 Jul 24 16:04:57 VERBOSE[2924] logger.c: Transmitting (NAT) to 194.120.0.203:5060: ACK sip:12488401204@sip.sipdiscount.com SIP/2.0 Via: SIP/2.0/UDP 10.24.0.12:5060;branch=z9hG4bK0e3e9ffa;rport From: "Patrick Synor" ;tag=as3b3dc4b6 To: Contact: Call-ID: 228596a67b1b217239b8535e5d7f6d5d@sipdiscount.com CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Remote-Party-ID: "Patrick Synor" ;privacy=off;screen=no Content-Length: 0 --- Jul 24 16:04:57 VERBOSE[5911] logger.c: -- SIP/voipdiscount-56b6 is circuit-busy Jul 24 16:04:57 DEBUG[5911] channel.c: Hanging up channel 'SIP/voipdiscount-56b6' Jul 24 16:04:57 DEBUG[5911] chan_sip.c: Hangup call SIP/voipdiscount-56b6, SIP callid 228596a67b1b217239b8535e5d7f6d5d@sipdiscount.com) Jul 24 16:04:57 DEBUG[5911] chan_sip.c: update_call_counter(12488401204) - decrement call limit counter Jul 24 16:04:57 VERBOSE[5911] logger.c: == Everyone is busy/congested at this time (1:0/1/0) Jul 24 16:04:57 DEBUG[5915] app_queue.c: Device 'SIP/voipdiscount' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jul 24 16:04:57 DEBUG[5911] app_dial.c: Exiting with DIALSTATUS=CONGESTION. Jul 24 16:04:57 DEBUG[5911] pbx.c: Launching 'Goto' Jul 24 16:04:57 VERBOSE[5911] logger.c: -- Executing Goto("SIP/111-b7ee", "s-CONGESTION|1") in new stack Jul 24 16:04:57 VERBOSE[5911] logger.c: -- Goto (macro-dialout-trunk,s-CONGESTION,1) Jul 24 16:04:57 DEBUG[5911] pbx.c: Launching 'NoOp' Jul 24 16:04:57 VERBOSE[5911] logger.c: -- Executing NoOp("SIP/111-b7ee", "Dial failed due to CONGESTION") in new stack Jul 24 16:04:57 DEBUG[5911] pbx.c: Launching 'Macro' Jul 24 16:04:57 VERBOSE[5911] logger.c: -- Executing Macro("SIP/111-b7ee", "outisbusy|") in new stack Jul 24 16:04:57 DEBUG[5911] pbx.c: Launching 'Playback' Jul 24 16:04:57 VERBOSE[5911] logger.c: -- Executing Playback("SIP/111-b7ee", "all-circuits-busy-now") in new stack Jul 24 16:04:57 DEBUG[2881] channel.c: Avoiding initial deadlock for 'SIP/111-b7ee' Jul 24 16:04:57 DEBUG[5911] chan_sip.c: sip_answer(SIP/111-b7ee) Jul 24 16:04:57 DEBUG[5911] channel.c: Set channel SIP/111-b7ee to write format gsm Jul 24 16:04:57 DEBUG[5911] rtp.c: Ooh, format changed from unknown to ulaw Jul 24 16:04:57 VERBOSE[5911] logger.c: -- Playing 'all-circuits-busy-now' (language 'en') Jul 24 16:04:57 DEBUG[5916] app_queue.c: Device 'SIP/111' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jul 24 16:04:57 DEBUG[2924] chan_sip.c: Stopping retransmission on 'af9f628af072786e@10.24.5.10' of Response 29440: Match Found Jul 24 16:04:57 VERBOSE[2924] logger.c: Destroying call '228596a67b1b217239b8535e5d7f6d5d@sipdiscount.com' Jul 24 16:04:59 DEBUG[5911] channel.c: Set channel SIP/111-b7ee to write format ulaw Jul 24 16:04:59 DEBUG[5911] pbx.c: Launching 'Playback' Jul 24 16:04:59 VERBOSE[5911] logger.c: -- Executing Playback("SIP/111-b7ee", "pls-try-call-later") in new stack Jul 24 16:04:59 DEBUG[5911] channel.c: Set channel SIP/111-b7ee to write format gsm Jul 24 16:04:59 VERBOSE[5911] logger.c: -- Playing 'pls-try-call-later' (language 'en') Jul 24 16:05:01 DEBUG[5911] channel.c: Set channel SIP/111-b7ee to write format ulaw Jul 24 16:05:01 DEBUG[5911] pbx.c: Launching 'Macro' Jul 24 16:05:01 VERBOSE[5911] logger.c: -- Executing Macro("SIP/111-b7ee", "hangupcall") in new stack Jul 24 16:05:01 DEBUG[5911] pbx.c: Launching 'ResetCDR' Jul 24 16:05:01 VERBOSE[5911] logger.c: -- Executing ResetCDR("SIP/111-b7ee", "w") in new stack Jul 24 16:05:01 DEBUG[5911] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. Jul 24 16:05:01 DEBUG[5911] 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,uniqueid) VALUES ('2006-07-24 16:04:56','\"Patrick Synor\" <111>','111','12488401204','from-internal', 'SIP/111-b7ee','SIP/voipdiscount-56b6','ResetCDR','w',5,4,'ANSWERED',3,'','1153771496.18') Jul 24 16:05:01 DEBUG[5911] pbx.c: Launching 'NoCDR' Jul 24 16:05:01 VERBOSE[5911] logger.c: -- Executing NoCDR("SIP/111-b7ee", "") in new stack Jul 24 16:05:01 WARNING[5911] cdr.c: CDR on channel 'SIP/111-b7ee' not posted Jul 24 16:05:01 WARNING[5911] cdr.c: CDR on channel 'SIP/111-b7ee' lacks end Jul 24 16:05:01 DEBUG[5911] pbx.c: Launching 'Wait' Jul 24 16:05:01 VERBOSE[5911] logger.c: -- Executing Wait("SIP/111-b7ee", "5") in new stack Jul 24 16:05:01 DEBUG[5911] app_macro.c: Spawn extension (macro-hangupcall,s,3) exited non-zero on 'SIP/111-b7ee' in macro 'hangupcall' Jul 24 16:05:01 DEBUG[5911] app_macro.c: Spawn extension (macro-hangupcall,s,3) exited non-zero on 'SIP/111-b7ee' in macro 'outisbusy' Jul 24 16:05:01 DEBUG[5911] pbx.c: Spawn extension (macro-hangupcall,s,3) exited non-zero on 'SIP/111-b7ee' Jul 24 16:05:01 DEBUG[5911] channel.c: Hanging up channel 'SIP/111-b7ee' Jul 24 16:05:01 DEBUG[5911] chan_sip.c: Hangup call SIP/111-b7ee, SIP callid af9f628af072786e@10.24.5.10) Jul 24 16:05:01 DEBUG[5911] chan_sip.c: update_call_counter(111) - decrement call limit counter Jul 24 16:05:01 DEBUG[5985] app_queue.c: Device 'SIP/111' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Jul 24 16:05:03 DEBUG[3082] manager.c: Manager received command 'Command' Jul 24 16:05:03 DEBUG[3082] manager.c: Manager received command 'Command' Jul 24 16:05:09 NOTICE[2924] chan_sip.c: -- Re-registration for 08154287@sip.stanaphone.com Jul 24 16:05:09 DEBUG[2924] chan_sip.c: Allocating new SIP dialog for 7fe969a00f31a13f3b9ae1aa76a1daa2@127.0.0.1 - REGISTER (No RTP) Jul 24 16:05:09 DEBUG[2924] chan_sip.c: Scheduled a registration timeout for sip.stanaphone.com id #490 Jul 24 16:05:09 DEBUG[2924] chan_sip.c: >>> Re-using Auth data for 08154287@sip.stanaphone.com Jul 24 16:05:09 NOTICE[2924] chan_sip.c: -- Re-registration for psy@iee.lu@sip.sipdiscount.com Jul 24 16:05:09 DEBUG[2924] chan_sip.c: Allocating new SIP dialog for 47023c29373bf61d714cbdd57d62a886@127.0.0.1 - REGISTER (No RTP) Jul 24 16:05:09 DEBUG[2924] chan_sip.c: Scheduled a registration timeout for sip.sipdiscount.com id #492 Jul 24 16:05:09 DEBUG[2924] chan_sip.c: >>> Re-using Auth data for psy@iee.lu@sip.sipdiscount.com Jul 24 16:05:10 DEBUG[2924] chan_sip.c: Stopping retransmission on '7fe969a00f31a13f3b9ae1aa76a1daa2@127.0.0.1' of Request 135: Match Found Jul 24 16:05:10 DEBUG[2924] chan_sip.c: Registration successful Jul 24 16:05:10 DEBUG[2924] chan_sip.c: Cancelling timeout 490 Jul 24 16:05:10 NOTICE[2924] chan_sip.c: Outbound Registration: Expiry for sip.stanaphone.com is 120 sec (Scheduling reregistration in 105 s) Jul 24 16:05:10 DEBUG[2924] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '47023c29373bf61d714cbdd57d62a886@127.0.0.1' Request 135: Found Jul 24 16:05:10 DEBUG[2924] chan_sip.c: Stopping retransmission on '47023c29373bf61d714cbdd57d62a886@127.0.0.1' of Request 135: Match Found Jul 24 16:05:10 DEBUG[2924] chan_sip.c: Registration successful Jul 24 16:05:10 DEBUG[2924] chan_sip.c: Cancelling timeout 492 Jul 24 16:05:10 NOTICE[2924] chan_sip.c: Outbound Registration: Expiry for sip.sipdiscount.com is 120 sec (Scheduling reregistration in 105 s) Jul 24 16:05:11 DEBUG[2924] chan_sip.c: Stopping retransmission on '7fe969a00f31a13f3b9ae1aa76a1daa2@127.0.0.1' of Request 135: Match Not Found Jul 24 16:05:11 WARNING[2924] chan_sip.c: Got 200 OK on REGISTER that isn't a register Jul 24 16:05:13 DEBUG[2924] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 24 16:05:13 VERBOSE[2924] logger.c: 12 headers, 0 lines Jul 24 16:05:13 VERBOSE[2924] logger.c: Reliably Transmitting (NAT) to 194.120.0.203:5060: OPTIONS sip:sip.sipdiscount.com SIP/2.0 Via: SIP/2.0/UDP 10.24.0.12:5060;branch=z9hG4bK14f8a917;rport From: "Unknown" ;tag=as1f15fb62 To: Contact: Call-ID: 2f63a2427e9f0e3423cbcecd66b9f7bc@10.24.0.12 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Mon, 24 Jul 2006 20:05:13 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Jul 24 16:05:14 VERBOSE[2924] logger.c: <-- SIP read from 194.120.0.203:5060: SIP/2.0 200 Ok Via: SIP/2.0/UDP 10.24.0.12:5060;branch=z9hG4bK14f8a917;rport From: "Unknown" ;tag=as1f15fb62 To: Contact: sip:194.120.0.203:5060 Call-ID: 2f63a2427e9f0e3423cbcecd66b9f7bc@10.24.0.12 CSeq: 102 OPTIONS Supported: User-Agent: (Very nice Sip Registrar Server) Allow: ACK,BYE,CANCEL,INVITE,REGISTER,OPTIONS Accept: application/sdp Accept-Encoding: Accept-Language: Jul 24 16:05:14 VERBOSE[2924] logger.c: --- (13 headers 0 lines)Jul 24 16:05:14 VERBOSE[2924] logger.c: --- (13 headers 0 lines)--- Jul 24 16:05:14 DEBUG[2924] chan_sip.c: Stopping retransmission on '2f63a2427e9f0e3423cbcecd66b9f7bc@10.24.0.12' of Request 102: Match Found Jul 24 16:05:14 VERBOSE[2924] logger.c: Destroying call '2f63a2427e9f0e3423cbcecd66b9f7bc@10.24.0.12' Jul 24 16:05:42 DEBUG[2924] chan_sip.c: Auto destroying call '47023c29373bf61d714cbdd57d62a886@127.0.0.1'