Connected to Asterisk 1.8.7.1 currently running on hostname (pid = 1365) Verbosity is at least 9 Core debug is at least 9 <--- SIP read from UDP:xx.xx.xx.25:58902 ---> OPTIONS sip:xx.xx.xx.25:5070 SIP/2.0 Via: SIP/2.0/UDP xx.xx.xx.25:48047;branch=z9hG4bK.2cf32d51;rport;alias From: sip:sipsak@xx.xx.xx.25:48047;tag=75a363ae To: sip:xx.xx.xx.25:5070 Call-ID: 1973642158@xx.xx.xx.25 CSeq: 1 OPTIONS Contact: sip:sipsak@xx.xx.xx.25:48047 Content-Length: 0 Max-Forwards: 70 User-Agent: sipsak 0.9.6 Accept: text/plain <-------------> --- (11 headers 0 lines) --- Looking for s in from-external (domain xx.xx.xx.25:5070) <--- Transmitting (NAT) to xx.xx.xx.25:58902 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP xx.xx.xx.25:48047;branch=z9hG4bK.2cf32d51;alias;received=xx.xx.xx.25;rport=58902 From: sip:sipsak@xx.xx.xx.25:48047;tag=75a363ae To: sip:xx.xx.xx.25:5070;tag=as1f72d639 Call-ID: 1973642158@xx.xx.xx.25 CSeq: 1 OPTIONS Server: product Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <------------> Scheduling destruction of SIP dialog '1973642158@xx.xx.xx.25' in 32000 ms (Method: OPTIONS) <--- SIP read from UDP:xx.xx.xx.25:5060 ---> INVITE sip:0000003@xx.xx.xx.25:5070;transport=udp SIP/2.0 Record-Route: Via: SIP/2.0/UDP xx.xx.xx.25;branch=z9hG4bK9d66.8b42f471.0 Via: SIP/2.0/UDP 10.0.0.214:5060;rport=19050;received=yy.yy.yy.241;branch=z9hG4bK-c70b447d From: "A C" ;tag=6a7ab41ba55021ddo0 To: "P M" Call-ID: ffacf773-ed86f665@10.0.0.214 CSeq: 102 INVITE Max-Forwards: 69 Proxy-Authorization: Digest username="0000004",realm="hostname.example.com",nonce="50e5b7010000fb89b26fb55d782a9b965016291fa7e10296",uri="sip:0000003@hostname.example.com",algorithm=MD5,response="6ab9b87038446e9cbb95b1b029f7a156" Contact: "A C" Expires: 240 User-Agent: Cisco/SPA502G-7.5.4 Content-Length: 439 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, UPDATE Supported: replaces Content-Type: application/sdp X-product-RURI: sip:0000003@hostname.example.com X-product-Source: yy.yy.yy.241:19050 v=0 o=- 855229 855229 IN IP4 10.0.0.214 s=- c=IN IP4 yy.yy.yy.241 t=0 0 m=audio 16454 RTP/AVP 9 0 2 8 18 96 97 98 101 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729a/8000 a=rtpmap:96 G726-40/8000 a=rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv a=direction:active a=oldmediaip:10.0.0.214 <-------------> --- (19 headers 20 lines) --- == Using UDPTL CoS mark 5 Sending to xx.xx.xx.25:5060 (NAT) Using INVITE request as basis request - ffacf773-ed86f665@10.0.0.214 Found peer 'product-local' for '0000004' from xx.xx.xx.25:5060 == Using SIP RTP CoS mark 5 Found RTP audio format 9 Found RTP audio format 0 Found RTP audio format 2 Found RTP audio format 8 Found RTP audio format 18 Found RTP audio format 96 Found RTP audio format 97 Found RTP audio format 98 Found RTP audio format 101 Found audio description format G722 for ID 9 Found audio description format PCMU for ID 0 Found audio description format G726-32 for ID 2 Found audio description format PCMA for ID 8 Found audio description format G729a for ID 18 Found unknown media description format G726-40 for ID 96 Found unknown media description format G726-24 for ID 97 Found unknown media description format G726-16 for ID 98 Found audio description format telephone-event for ID 101 Capabilities: us - 0x1fee (gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g722), peer - audio=0x190c (ulaw|alaw|g726|g729|g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x190c (ulaw|alaw|g726|g729|g722) Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) Peer audio RTP is at port yy.yy.yy.241:16454 Looking for 0000003 in from-internal (domain xx.xx.xx.25:5070) list_route: hop: <--- Transmitting (NAT) to xx.xx.xx.25:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP xx.xx.xx.25;branch=z9hG4bK9d66.8b42f471.0;received=xx.xx.xx.25;rport=5060 Via: SIP/2.0/UDP 10.0.0.214:5060;rport=19050;received=yy.yy.yy.241;branch=z9hG4bK-c70b447d Record-Route: From: "A C" ;tag=6a7ab41ba55021ddo0 To: "P M" Call-ID: ffacf773-ed86f665@10.0.0.214 CSeq: 102 INVITE Server: product Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> -- Executing [0000003@from-internal:1] AGI("SIP/product-local-00000407", "agi://127.0.0.1/product?stype=internal") in new stack AGI Tx >> agi_network: yes AGI Tx >> agi_network_script: product?stype=internal AGI Tx >> agi_request: agi://127.0.0.1/product?stype=internal AGI Tx >> agi_channel: SIP/product-local-00000407 AGI Tx >> agi_language: en AGI Tx >> agi_type: SIP AGI Tx >> agi_uniqueid: 1357231843.2187 AGI Tx >> agi_version: 1.8.7.1 AGI Tx >> agi_callerid: 0000004 AGI Tx >> agi_calleridname: A C AGI Tx >> agi_callingpres: 0 AGI Tx >> agi_callingani2: 0 AGI Tx >> agi_callington: 0 AGI Tx >> agi_callingtns: 0 AGI Tx >> agi_dnid: 0000003 AGI Tx >> agi_rdnis: unknown AGI Tx >> agi_context: from-internal AGI Tx >> agi_extension: 0000003 AGI Tx >> agi_priority: 1 AGI Tx >> agi_enhanced: 0.0 AGI Tx >> agi_accountcode: AGI Tx >> agi_threadid: 47926434608896 AGI Tx >> AGI Rx << VERBOSE "AGI starting at Thu Jan 3 16:50:43 2013 (1357231843)" 9 > agi://127.0.0.1/product?stype=internal: AGI starting at Thu Jan 3 16:50:43 2013 (1357231843) AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE CHANNEL(language) en AGI Tx >> 200 result=1 AGI Rx << GET VARIABLE product-CALLID AGI Tx >> 200 result=0 AGI Rx << SET VARIABLE __product-CALLID "1357231843.2187" AGI Tx >> 200 result=1 AGI Rx << GET VARIABLE product-SCREEN AGI Tx >> 200 result=0 AGI Rx << GET VARIABLE product-DIVERTED AGI Tx >> 200 result=0 AGI Rx << GET VARIABLE product-DIVERSION AGI Tx >> 200 result=0 AGI Rx << SET VARIABLE __product-MUSIC "default" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE CHANNEL(musicclass) "default" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __TRANSFER_CONTEXT "from-internal" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE TIMEOUT(absolute) "86400" Channel will hangup at 2013-01-04 16:50:43.429 GMT. AGI Tx >> 200 result=1 AGI Rx << GET VARIABLE product-CUTOFF AGI Tx >> 200 result=0 AGI Rx << SET VARIABLE TIMEOUT(absolute) "86400" Channel will hangup at 2013-01-04 16:50:43.430 GMT. AGI Tx >> 200 result=1 AGI Rx << GET VARIABLE SIP_HEADER(Call-ID) AGI Tx >> 200 result=1 (ffacf773-ed86f665@10.0.0.214) AGI Rx << VERBOSE "SIP Call-ID is: ffacf773-ed86f665@10.0.0.214" 9 > agi://127.0.0.1/product?stype=internal: SIP Call-ID is: ffacf773-ed86f665@10.0.0.214 AGI Tx >> 200 result=1 AGI Rx << GET VARIABLE product-SCUSTOMER AGI Tx >> 200 result=0 AGI Rx << GET VARIABLE SIP_HEADER(X-product-Source) AGI Tx >> 200 result=1 (yy.yy.yy.241:19050) AGI Rx << GET VARIABLE product-PRESENTATION-INTERNAL AGI Tx >> 200 result=0 AGI Rx << GET VARIABLE product-PRESENTATION-EXTERNAL AGI Tx >> 200 result=0 AGI Rx << GET VARIABLE SIP_HEADER(X-product-External) AGI Tx >> 200 result=0 AGI Rx << GET VARIABLE product-TRANSFER-PHONE AGI Tx >> 200 result=0 AGI Rx << GET VARIABLE product-TRANSFER-CUSTOMER AGI Tx >> 200 result=0 AGI Rx << GET VARIABLE SIP_HEADER(Proxy-Authorization) AGI Tx >> 200 result=1 (Digest username="0000004",realm="hostname.example.com",nonce="50e5b7010000fb89b26fb55d782a9b965016291fa7e10296",uri="sip:0000003@hostname.example.com",algorithm=MD5,response="6ab9b87038446e9cbb95b1b029f7a156") AGI Rx << SET VARIABLE __product-MUSIC "10" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE CHANNEL(musicclass) "10" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __SIPADDHEADER01 "Alert-Info: Simple-1" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE CHANNEL(language) en AGI Tx >> 200 result=1 AGI Rx << VERBOSE "Resolving type '', number '0000003', old '', forward 1 for channel SIP/product-local-00000407" 5 > agi://127.0.0.1/product?stype=internal: Resolving type '', number '0000003', old '', forward 1 for channel SIP/product-local-00000407 AGI Tx >> 200 result=1 AGI Rx << VERBOSE "Starting recording group '1' expires '1358441443' file '/var/lib/product/recordings/2/1/2013/01/03/record_13572318432187_24709'" 9 > agi://127.0.0.1/product?stype=internal: Starting recording group '1' expires '1358441443' file '/var/lib/product/recordings/2/1/2013/01/03/record_13572318432187_24709' AGI Tx >> 200 result=1 AGI Rx << EXEC Monitor gsm,/var/lib/product/recordings/2/1/2013/01/03/record_13572318432187_24709 -- AGI Script Executing Application: (Monitor) Options: (gsm,/var/lib/product/recordings/2/1/2013/01/03/record_13572318432187_24709) AGI Tx >> 200 result=0 AGI Rx << GET VARIABLE product-QUEUE AGI Tx >> 200 result=0 AGI Rx << GET VARIABLE SIP_HEADER(Call-ID) AGI Tx >> 200 result=1 (ffacf773-ed86f665@10.0.0.214) AGI Rx << GET VARIABLE CALLERID(name) AGI Tx >> 200 result=1 (A C) AGI Rx << VERBOSE "Writing entry to active table for 1357231843.2187, phone:0000004 - phone:0000003." 9 > agi://127.0.0.1/product?stype=internal: Writing entry to active table for 1357231843.2187, phone:0000004 - phone:0000003. AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE TIMEOUT(absolute) "86400" Channel will hangup at 2013-01-04 16:50:43.526 GMT. AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __product-DCUSTOMER "2" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __product-DTYPE "phone" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __product-DNUMBER "0000003" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE CALLERID(number) "0000004" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __product-TRANSFER-CUSTOMER "2" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __product-PRESENTATION-INTERNAL "1" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __product-PRESENTATION-EXTERNAL "1" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __product-CUTOFF "86400" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __product-PHONE-DOMAIN "xx.xx.xx.25:5060" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __product-PHONE-OPTS "ortM(product-answered^0^1357231843.2187)" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __SIPADDHEADER11 "X-product-Uniqueid: 1357231843.2187" AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE __product-TRANSFER-PHONE "0000003" AGI Tx >> 200 result=1 AGI Rx << EXEC Dial Local/0000003@product-phone/n,20,o -- AGI Script Executing Application: (Dial) Options: (Local/0000003@product-phone/n,20,o) -- Called Local/0000003@product-phone/n -- Executing [0000003@product-phone:1] GotoIf("Local/0000003@product-phone-fbe7;2", "0?3") in new stack -- Executing [0000003@product-phone:2] SetMusicOnHold("Local/0000003@product-phone-fbe7;2", "10") in new stack -- Executing [0000003@product-phone:3] Dial("Local/0000003@product-phone-fbe7;2", "SIP/0000003@xx.xx.xx.25:5060,3600,ortM(product-answered^0^1357231843.2187)") in new stack == Using UDPTL CoS mark 5 == Using SIP RTP CoS mark 5 Audio is at 5070 Adding codec 0x1000 (g722) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x40 (slin) to SDP Adding codec 0x2 (gsm) to SDP Adding codec 0x800 (g726) to SDP Adding codec 0x20 (adpcm) to SDP Adding codec 0x80 (lpc10) to SDP Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP Reliably Transmitting (NAT) to xx.xx.xx.25:5060: INVITE sip:0000003@xx.xx.xx.25:5060 SIP/2.0 Via: SIP/2.0/UDP xx.xx.xx.25:5070;branch=z9hG4bK53ffbf3d;rport Max-Forwards: 70 From: "A C" ;tag=as088732f7 To: Contact: Call-ID: 511c985c539bdf3367837bfc52678bcb@xx.xx.xx.25:5070 CSeq: 102 INVITE User-Agent: product Date: Thu, 03 Jan 2013 16:50:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-product-Uniqueid: 1357231843.2187 Alert-Info: Simple-1 Content-Type: application/sdp Content-Length: 453 v=0 o=root 83150578 83150578 IN IP4 xx.xx.xx.25 s=Asterisk PBX 1.8.7.1 c=IN IP4 xx.xx.xx.25 t=0 0 m=audio 16598 RTP/AVP 9 0 8 10 3 111 5 7 18 101 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:10 L16/8000 a=rtpmap:3 GSM/8000 a=rtpmap:111 G726-32/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:7 LPC/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv --- -- Called SIP/0000003@xx.xx.xx.25:5060 -- Local/0000003@product-phone-fbe7;1 is ringing <--- Transmitting (NAT) to xx.xx.xx.25:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP xx.xx.xx.25;branch=z9hG4bK9d66.8b42f471.0;received=xx.xx.xx.25;rport=5060 Via: SIP/2.0/UDP 10.0.0.214:5060;rport=19050;received=yy.yy.yy.241;branch=z9hG4bK-c70b447d Record-Route: From: "A C" ;tag=6a7ab41ba55021ddo0 To: "P M" ;tag=as1d1109d9 Call-ID: ffacf773-ed86f665@10.0.0.214 Seq: 102 INVITE Server: product Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> <--- SIP read from UDP:xx.xx.xx.25:5060 ---> SIP/2.0 100 Giving a try Via: SIP/2.0/UDP xx.xx.xx.25:5070;branch=z9hG4bK53ffbf3d;rport=5070 From: "A C" ;tag=as088732f7 To: Call-ID: 511c985c539bdf3367837bfc52678bcb@xx.xx.xx.25:5070 CSeq: 102 INVITE Server: product SIP proxy Content-Length: 0 Warning: 392 xx.xx.xx.25:5060 "Noisy feedback tells: pid=1956 req_src_ip=xx.xx.xx.25 req_src_port=5070 in_uri=sip:0000003@xx.xx.xx.25:5060 out_uri=sip:0000003@10.0.0.213:5060 via_cnt==1" <-------------> --- (9 headers 0 lines) --- <--- SIP read from UDP:xx.xx.xx.25:5060 ---> SIP/2.0 180 Ringing To: ;tag=11f13cdd251463fdi0 From: "A C" ;tag=as088732f7 Call-ID: 511c985c539bdf3367837bfc52678bcb@xx.xx.xx.25:5070 CSeq: 102 INVITE Via: SIP/2.0/UDP xx.xx.xx.25:5070;received=xx.xx.xx.25;branch=z9hG4bK53ffbf3d;rport=5070 Record-Route: Contact: "P M" Server: Cisco/SPA502G-7.5.3 Content-Length: 0 <-------------> --- (10 headers 0 lines) --- -- SIP/xx.xx.xx.25:5060-00000408 is ringing -- Local/0000003@product-phone-fbe7;1 is ringing <--- SIP read from UDP:xx.xx.xx.25:5060 ---> SIP/2.0 200 OK To: ;tag=11f13cdd251463fdi0 From: "A C" ;tag=as088732f7 Call-ID: 511c985c539bdf3367837bfc52678bcb@xx.xx.xx.25:5070 CSeq: 102 INVITE Via: SIP/2.0/UDP xx.xx.xx.25:5070;received=xx.xx.xx.25;branch=z9hG4bK53ffbf3d;rport=5070 Record-Route: Contact: "P M" Server: Cisco/SPA502G-7.5.3 Content-Length: 250 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER, UPDATE Supported: replaces Content-Type: application/sdp v=0 o=- 856247 856247 IN IP4 10.0.0.213 s=- c=IN IP4 yy.yy.yy.241 t=0 0 m=audio 16442 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv a=direction:active a=oldmediaip:10.0.0.213 <-------------> --- (13 headers 13 lines) --- Found RTP audio format 9 Found RTP audio format 101 Found audio description format G722 for ID 9 Found audio description format telephone-event for ID 101 Capabilities: us - 0x1fee (gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|ilbc|g722), peer - audio=0x1000 (g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x1000 (g722) Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) Peer audio RTP is at port yy.yy.yy.241:16442 list_route: hop: set_destination: Parsing for address/port to send to set_destination: set destination to xx.xx.xx.25:5060 Transmitting (NAT) to xx.xx.xx.25:5060: ACK sip:0000003@yy.yy.yy.241:59990 SIP/2.0 Via: SIP/2.0/UDP xx.xx.xx.25:5070;branch=z9hG4bK16415739;rport Route: Max-Forwards: 70 From: "A C" ;tag=as088732f7 To: ;tag=11f13cdd251463fdi0 Contact: Call-ID: 511c985c539bdf3367837bfc52678bcb@xx.xx.xx.25:5070 CSeq: 102 ACK User-Agent: product Content-Length: 0 --- -- SIP/xx.xx.xx.25:5060-00000408 answered Local/0000003@product-phone-fbe7;2 -- Executing [s@macro-product-answered:1] AGI("SIP/xx.xx.xx.25:5060-00000408", "agi://127.0.0.1/answered?screen=0&puniqueid=1357231843.2187&pcallid=&snumber=") in new stack AGI Tx >> agi_network: yes AGI Tx >> agi_network_script: answered?screen=0&puniqueid=1357231843.2187&pcallid=&snumber= AGI Tx >> agi_request: agi://127.0.0.1/answered?screen=0&puniqueid=1357231843.2187&pcallid=&snumber= AGI Tx >> agi_channel: SIP/xx.xx.xx.25:5060-00000408 AGI Tx >> agi_language: en AGI Tx >> agi_type: SIP AGI Tx >> agi_uniqueid: 1357231843.2190 AGI Tx >> agi_version: 1.8.7.1 AGI Tx >> agi_callerid: 0000004 AGI Tx >> agi_calleridname: A C AGI Tx >> agi_callingpres: 0 AGI Tx >> agi_callingani2: 0 AGI Tx >> agi_callington: 0 AGI Tx >> agi_callingtns: 0 AGI Tx >> agi_dnid: unknown AGI Tx >> agi_rdnis: unknown AGI Tx >> agi_context: macro-product-answered AGI Tx >> agi_extension: s AGI Tx >> agi_priority: 1 AGI Tx >> agi_enhanced: 0.0 AGI Tx >> agi_accountcode: AGI Tx >> agi_threadid: 47926432065280 AGI Tx >> AGI Rx << VERBOSE "AGI starting at Thu Jan 3 16:50:44 2013 (1357231844)" 9 > agi://127.0.0.1/answered?screen=0&puniqueid=1357231843.2187&pcallid=&snumber=: AGI starting at Thu Jan 3 16:50:44 2013 (1357231844) AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE CHANNEL(language) en AGI Tx >> 200 result=1 AGI Rx << GET VARIABLE product-CALLID AGI Tx >> 200 result=1 (1357231843.2187) Really destroying SIP dialog '2049225576@xx.xx.xx.25' Method: OPTIONS AGI Rx << SET VARIABLE MACRO_RESULT "" AGI Tx >> 200 result=1 AGI Rx << GET VARIABLE product-TRANSFERRED-BY AGI Tx >> 200 result=0 -- AGI Script agi://127.0.0.1/answered?screen=0&puniqueid=1357231843.2187&pcallid=&snumber= completed, returning 0 -- Local/0000003@product-phone-fbe7;1 stopped sounds -- Local/0000003@product-phone-fbe7;1 answered SIP/product-local-00000407 Audio is at 5070 Adding codec 0x1000 (g722) to SDP Adding codec 0x4 (ulaw) to SDP Adding codec 0x8 (alaw) to SDP Adding codec 0x800 (g726) to SDP Adding codec 0x100 (g729) to SDP Adding non-codec 0x1 (telephone-event) to SDP <--- Reliably Transmitting (NAT) to xx.xx.xx.25:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP xx.xx.xx.25;branch=z9hG4bK9d66.8b42f471.0;received=xx.xx.xx.25;rport=5060 Via: SIP/2.0/UDP 10.0.0.214:5060;rport=19050;received=yy.yy.yy.241;branch=z9hG4bK-c70b447d Record-Route: From: "A C" ;tag=6a7ab41ba55021ddo0 To: "P M" ;tag=as1d1109d9 Call-ID: ffacf773-ed86f665@10.0.0.214 CSeq: 102 INVITE Server: product Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 358 v=0 o=root 2087263229 2087263229 IN IP4 xx.xx.xx.25 s=Asterisk PBX 1.8.7.1 c=IN IP4 xx.xx.xx.25 t=0 0 m=audio 11474 RTP/AVP 9 0 8 2 18 101 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <------------> <--- SIP read from UDP:xx.xx.xx.25:5060 ---> ACK sip:0000003@xx.xx.xx.25:5070;transport=udp SIP/2.0 Record-Route: Via: SIP/2.0/UDP xx.xx.xx.25;branch=z9hG4bK9d66.8b42f471.2 Via: SIP/2.0/UDP 10.0.0.214:5060;rport=19050;received=yy.yy.yy.241;branch=z9hG4bK-ebcba5a1 From: "A C" ;tag=6a7ab41ba55021ddo0 To: "P M" ;tag=as1d1109d9 Call-ID: ffacf773-ed86f665@10.0.0.214 CSeq: 102 ACK Max-Forwards: 69 Route: Proxy-Authorization: Digest username="0000004",realm="hostname.example.com",nonce="50e5b7010000fb89b26fb55d782a9b965016291fa7e10296",uri="sip:0000003@hostname.example.com",algorithm=MD5,response="6ab9b87038446e9cbb95b1b029f7a156" Contact: "A C" User-Agent: Cisco/SPA502G-7.5.4 Content-Length: 0 X-product-RURI: sip:0000003@xx.xx.xx.25:5070 X-product-Source: yy.yy.yy.241:19050 <-------------> --- (16 headers 0 lines) --- Really destroying SIP dialog '945eefc1-e111ef6b@192.168.1.46' Method: BYE <--- SIP read from UDP:xx.xx.xx.25:5060 ---> BYE sip:0000004@xx.xx.xx.25:5070;transport=udp SIP/2.0 Record-Route: Via: SIP/2.0/UDP xx.xx.xx.25;branch=z9hG4bKf80d.50f19c37.0 Via: SIP/2.0/UDP 10.0.0.213:5060;rport=59990;received=yy.yy.yy.241;branch=z9hG4bK-4fab809d From: ;tag=11f13cdd251463fdi0 To: "A C" ;tag=as088732f7 Call-ID: 511c985c539bdf3367837bfc52678bcb@xx.xx.xx.25:5070 CSeq: 101 BYE Max-Forwards: 69 Route: User-Agent: Cisco/SPA502G-7.5.3 Content-Length: 0 X-product-RURI: sip:0000004@xx.xx.xx.25:5070 X-product-Source: yy.yy.yy.241:59990 <-------------> --- (14 headers 0 lines) --- Sending to xx.xx.xx.25:5060 (NAT) Scheduling destruction of SIP dialog '511c985c539bdf3367837bfc52678bcb@xx.xx.xx.25:5070' in 32000 ms (Method: BYE) <--- Transmitting (NAT) to xx.xx.xx.25:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP xx.xx.xx.25;branch=z9hG4bKf80d.50f19c37.0;received=xx.xx.xx.25;rport=5060 Via: SIP/2.0/UDP 10.0.0.213:5060;rport=59990;received=yy.yy.yy.241;branch=z9hG4bK-4fab809d Record-Route: From: ;tag=11f13cdd251463fdi0 To: "A C" ;tag=as088732f7 Call-ID: 511c985c539bdf3367837bfc52678bcb@xx.xx.xx.25:5070 CSeq: 101 BYE Server: product Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> == Spawn extension (product-phone, 0000003, 3) exited non-zero on 'Local/0000003@product-phone-fbe7;2' -- Executing [h@from-internal:1] AGI("SIP/product-local-00000407", "agi://127.0.0.1/end") in new stack AGI Tx >> agi_network: yes AGI Tx >> agi_network_script: end AGI Tx >> agi_request: agi://127.0.0.1/end AGI Tx >> agi_channel: SIP/product-local-00000407 AGI Tx >> agi_language: en AGI Tx >> agi_type: SIP AGI Tx >> agi_uniqueid: 1357231843.2187 AGI Tx >> agi_version: 1.8.7.1 AGI Tx >> agi_callerid: 0000004 AGI Tx >> agi_calleridname: A C AGI Tx >> agi_callingpres: 0 AGI Tx >> agi_callingani2: 0 AGI Tx >> agi_callington: 0 AGI Tx >> agi_callingtns: 0 AGI Tx >> agi_dnid: 0000003 AGI Tx >> agi_rdnis: unknown AGI Tx >> agi_context: from-internal AGI Tx >> agi_extension: h AGI Tx >> agi_priority: 1 AGI Tx >> agi_enhanced: 0.0 AGI Tx >> agi_accountcode: AGI Tx >> agi_threadid: 47926434608896 AGI Tx >> AGI Rx << VERBOSE "AGI starting at Thu Jan 3 16:50:47 2013 (1357231847)" 9 > agi://127.0.0.1/end: AGI starting at Thu Jan 3 16:50:47 2013 (1357231847) AGI Tx >> 200 result=1 AGI Rx << SET VARIABLE CHANNEL(language) en AGI Tx >> 200 result=1 AGI Rx << GET VARIABLE product-CALLID AGI Tx >> 200 result=1 (1357231843.2187) AGI Rx << GET VARIABLE ANSWEREDTIME AGI Tx >> 200 result=1 (3) AGI Rx << GET VARIABLE DIALSTATUS AGI Tx >> 200 result=1 (ANSWER) -- AGI Script agi://127.0.0.1/end completed, returning 0 AGI Tx >> 200 result=-1 AGI Rx << SET VARIABLE __product-TRANSFER-PHONE "" AGI Tx >> 200 result=1 AGI Rx << GET VARIABLE DIALSTATUS AGI Tx >> 200 result=1 (ANSWER) -- AGI Script agi://127.0.0.1/product?stype=internal completed, returning 0 -- Auto fallthrough, channel 'SIP/product-local-00000407' status is 'ANSWER' Scheduling destruction of SIP dialog 'ffacf773-ed86f665@10.0.0.214' in 32000 ms (Method: ACK) set_destination: Parsing for address/port to send to set_destination: set destination to xx.xx.xx.25:5060 Reliably Transmitting (NAT) to xx.xx.xx.25:5060: BYE sip:0000004@yy.yy.yy.241:19050 SIP/2.0 Via: SIP/2.0/UDP xx.xx.xx.25:5070;branch=z9hG4bK42bd0f5d;rport Route: Max-Forwards: 70 From: "P M" ;tag=as1d1109d9 To: "A C" ;tag=6a7ab41ba55021ddo0 Call-ID: ffacf773-ed86f665@10.0.0.214 CSeq: 102 BYE User-Agent: product X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- <--- SIP read from UDP:xx.xx.xx.25:5060 ---> SIP/2.0 200 OK To: "A C" ;tag=6a7ab41ba55021ddo0 From: "P M" ;tag=as1d1109d9 Call-ID: ffacf773-ed86f665@10.0.0.214 CSeq: 102 BYE Via: SIP/2.0/UDP xx.xx.xx.25:5070;received=xx.xx.xx.25;branch=z9hG4bK42bd0f5d;rport=5070 Record-Route: Server: Cisco/SPA502G-7.5.4 Content-Length: 0 <-------------> --- (9 headers 0 lines) --- SIP Response message for INCOMING dialog BYE arrived Really destroying SIP dialog 'ffacf773-ed86f665@10.0.0.214' Method: ACK hostname*CLI> Disconnected from Asterisk server