[Oct 24 09:03:42] VERBOSE[17424] chan_sip.c: <--- SIP read from UDP:x.x.x.149:5060 ---> <-------------> [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: <--- SIP read from UDP:x.x.x.149:5060 ---> INVITE sip:3300@voip.mydomain.com:5060;user=phone SIP/2.0 Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bKe89653148B0478D From: "John Smith" ;tag=189C9E06-F1F58017 To: CSeq: 1 INVITE Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.2.3.1734 Accept-Language: en Supported: 100rel,replaces Allow-Events: talk,hold,conference Max-Forwards: 70 Content-Type: application/sdp Content-Length: 292 v=0 o=- 1287897945 1287897945 IN IP4 x.x.x.149 s=Polycom IP Phone c=IN IP4 x.x.x.149 t=0 0 a=sendrecv m=audio 2222 RTP/AVP 9 0 8 18 127 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:127 telephone-event/8000 <-------------> [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: --- (15 headers 13 lines) --- [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Sending to x.x.x.149:5060 (no NAT) [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Using INVITE request as basis request - 377f46d2-e33a33f3-b78458c0@x.x.x.149 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found peer '1050' for '1050' from x.x.x.149:5060 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: <--- Reliably Transmitting (NAT) to x.x.x.149:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bKe89653148B0478D;received=x.x.x.149;rport=5060 From: "John Smith" ;tag=189C9E06-F1F58017 To: ;tag=as4879a025 Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 CSeq: 1 INVITE Server: Asterisk PBX 1.8.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="29fff2aa" Content-Length: 0 <------------> [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Scheduling destruction of SIP dialog '377f46d2-e33a33f3-b78458c0@x.x.x.149' in 6400 ms (Method: INVITE) [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: <--- SIP read from UDP:x.x.x.149:5060 ---> ACK sip:3300@voip.mydomain.com:5060;user=phone SIP/2.0 Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bKe89653148B0478D From: "John Smith" ;tag=189C9E06-F1F58017 To: ;tag=as4879a025 CSeq: 1 ACK Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.2.3.1734 Accept-Language: en Max-Forwards: 70 Content-Length: 0 <-------------> [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: --- (12 headers 0 lines) --- [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: <--- SIP read from UDP:x.x.x.149:5060 ---> INVITE sip:3300@voip.mydomain.com:5060;user=phone SIP/2.0 Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bKbddb8ec931B745E From: "John Smith" ;tag=189C9E06-F1F58017 To: CSeq: 2 INVITE Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.2.3.1734 Accept-Language: en Supported: 100rel,replaces Allow-Events: talk,hold,conference Authorization: Digest username="1050", realm="asterisk", nonce="29fff2aa", uri="sip:3300@voip.mydomain.com:5060;user=phone", response="2043e2887631e49c9316a982cff1ef65", algorithm=MD5 Max-Forwards: 70 Content-Type: application/sdp Content-Length: 292 v=0 o=- 1287897945 1287897945 IN IP4 x.x.x.149 s=Polycom IP Phone c=IN IP4 x.x.x.149 t=0 0 a=sendrecv m=audio 2222 RTP/AVP 9 0 8 18 127 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:127 telephone-event/8000 <-------------> [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: --- (16 headers 13 lines) --- [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Sending to x.x.x.149:5060 (NAT) [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Using INVITE request as basis request - 377f46d2-e33a33f3-b78458c0@x.x.x.149 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found peer '1050' for '1050' from x.x.x.149:5060 [Oct 24 09:03:45] VERBOSE[17424] netsock2.c: == Using SIP RTP TOS bits 184 [Oct 24 09:03:45] VERBOSE[17424] netsock2.c: == Using SIP RTP CoS mark 5 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found RTP audio format 9 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found RTP audio format 0 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found RTP audio format 8 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found RTP audio format 18 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found RTP audio format 127 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found audio description format G722 for ID 9 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found audio description format PCMU for ID 0 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found audio description format PCMA for ID 8 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found audio description format G729 for ID 18 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Found audio description format telephone-event for ID 127 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x110c (ulaw|alaw|g729|g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Peer audio RTP is at port x.x.x.149:2222 [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Looking for 3300 in from-internal (domain voip.mydomain.com:5060) [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: list_route: hop: [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: <--- Transmitting (NAT) to x.x.x.149:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bKbddb8ec931B745E;received=x.x.x.149;rport=5060 From: "John Smith" ;tag=189C9E06-F1F58017 To: Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 CSeq: 2 INVITE Server: Asterisk PBX 1.8.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [3300@from-internal:1] Macro("SIP/1050-00000000", "user-callerid,SKIPTTL,") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-user-callerid:1] Set("SIP/1050-00000000", "AMPUSER=1050") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/1050-00000000", "0?report") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/1050-00000000", "1?Set(REALCALLERIDNUM=1050)") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-user-callerid:4] Set("SIP/1050-00000000", "AMPUSER=2000") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-user-callerid:5] Set("SIP/1050-00000000", "AMPUSERCIDNAME=John Smith") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/1050-00000000", "0?report") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-user-callerid:7] Set("SIP/1050-00000000", "AMPUSERCID=2000") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-user-callerid:8] Set("SIP/1050-00000000", "CALLERID(all)="John Smith" <2000>") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-user-callerid:9] GotoIf("SIP/1050-00000000", "1?continue") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Goto (macro-user-callerid,s,18) [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-user-callerid:18] NoOp("SIP/1050-00000000", "Using CallerID "John Smith" <2000>") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [3300@from-internal:2] Set("SIP/1050-00000000", "INTRACOMPANYROUTE=YES") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [3300@from-internal:3] Set("SIP/1050-00000000", "_NODEST=") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [3300@from-internal:4] Macro("SIP/1050-00000000", "record-enable,2000,OUT,") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/1050-00000000", "1?check") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Goto (macro-record-enable,s,4) [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-record-enable:4] ExecIf("SIP/1050-00000000", "0?MacroExit()") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-record-enable:5] GotoIf("SIP/1050-00000000", "0?Group:OUT") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Goto (macro-record-enable,s,15) [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-record-enable:15] GotoIf("SIP/1050-00000000", "0?IN") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-record-enable:16] ExecIf("SIP/1050-00000000", "1?MacroExit()") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [3300@from-internal:5] Macro("SIP/1050-00000000", "dialout-trunk,5,3300,,") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/1050-00000000", "DIAL_TRUNK=5") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:2] GosubIf("SIP/1050-00000000", "0?sub-pincheck,s,1") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:3] GotoIf("SIP/1050-00000000", "0?disabletrunk,1") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:4] Set("SIP/1050-00000000", "DIAL_NUMBER=3300") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:5] Set("SIP/1050-00000000", "DIAL_TRUNK_OPTIONS=trTwW") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:6] Set("SIP/1050-00000000", "OUTBOUND_GROUP=OUT_5") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:7] GotoIf("SIP/1050-00000000", "1?nomax") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Goto (macro-dialout-trunk,s,9) [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:9] GotoIf("SIP/1050-00000000", "1?skipoutcid") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Goto (macro-dialout-trunk,s,12) [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:12] ExecIf("SIP/1050-00000000", "0?AGI(fixlocalprefix)") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:13] Set("SIP/1050-00000000", "OUTNUM=3300") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:14] Set("SIP/1050-00000000", "custom=SIP/exchange-vm") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:15] ExecIf("SIP/1050-00000000", "0?Set(DIAL_TRUNK_OPTIONS=M(setmusic^)trTwW)") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:16] Macro("SIP/1050-00000000", "dialout-trunk-predial-hook,") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk-predial-hook:1] MacroExit("SIP/1050-00000000", "") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:17] GotoIf("SIP/1050-00000000", "0?bypass,1") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:18] GotoIf("SIP/1050-00000000", "0?customtrunk") in new stack [Oct 24 09:03:45] VERBOSE[17440] pbx.c: -- Executing [s@macro-dialout-trunk:19] Dial("SIP/1050-00000000", "SIP/exchange-vm/3300,300,trTwW") in new stack [Oct 24 09:03:45] VERBOSE[17440] netsock2.c: == Using SIP RTP TOS bits 184 [Oct 24 09:03:45] VERBOSE[17440] netsock2.c: == Using SIP RTP CoS mark 5 [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Audio is at 5060 [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Reliably Transmitting (no NAT) to x.x.x.31:5060: INVITE sip:3300@x.x.x.31:5060 SIP/2.0 Via: SIP/2.0/TCP x.x.x.17:5060;branch=z9hG4bK62e7012d Max-Forwards: 70 From: "John Smith" ;tag=as1da7b780 To: Contact: Call-ID: 3568167a3902d35b5f4119fa551d9813@voip.mydomain.com CSeq: 102 INVITE User-Agent: Asterisk PBX 1.8.0 Date: Sun, 24 Oct 2010 13:03:45 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 254 v=0 o=root 1326365389 1326365389 IN IP4 x.x.x.17 s=Asterisk PBX 1.8.0 c=IN IP4 x.x.x.17 t=0 0 m=audio 10042 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=ptime:20 a=sendrecv --- [Oct 24 09:03:45] VERBOSE[17440] app_dial.c: -- Called exchange-vm/3300 [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: <--- Transmitting (NAT) to x.x.x.149:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bKbddb8ec931B745E;received=x.x.x.149;rport=5060 From: "John Smith" ;tag=189C9E06-F1F58017 To: ;tag=as06804e2e Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 CSeq: 2 INVITE Server: Asterisk PBX 1.8.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Oct 24 09:03:45] VERBOSE[17441] chan_sip.c: <--- SIP read from TCP:x.x.x.31:5060 ---> SIP/2.0 100 Trying FROM: "John Smith";tag=as1da7b780 TO: CSEQ: 102 INVITE CALL-ID: 3568167a3902d35b5f4119fa551d9813@voip.mydomain.com VIA: SIP/2.0/TCP x.x.x.17:5060;branch=z9hG4bK62e7012d CONTENT-LENGTH: 0 <-------------> [Oct 24 09:03:45] VERBOSE[17441] chan_sip.c: --- (7 headers 0 lines) --- [Oct 24 09:03:45] VERBOSE[17441] chan_sip.c: <--- SIP read from TCP:x.x.x.31:5060 ---> SIP/2.0 302 Moved Temporarily FROM: "John Smith";tag=as1da7b780 TO: ;epid=6E5119E026;tag=d823c5636 CSEQ: 102 INVITE CALL-ID: 3568167a3902d35b5f4119fa551d9813@voip.mydomain.com VIA: SIP/2.0/TCP x.x.x.17:5060;branch=z9hG4bK62e7012d CONTACT: CONTENT-LENGTH: 0 SERVER: RTCC/3.5.0.0 <-------------> [Oct 24 09:03:45] VERBOSE[17441] chan_sip.c: --- (9 headers 0 lines) --- [Oct 24 09:03:45] VERBOSE[17441] chan_sip.c: -- Got SIP response 302 "Moved Temporarily" back from x.x.x.31:5060 [Oct 24 09:03:45] VERBOSE[17440] app_dial.c: -- Now forwarding SIP/1050-00000000 to 'SIP/3300::::TCP@x.x.x.31:5065' (thanks to SIP/exchange-vm-00000001) [Oct 24 09:03:45] VERBOSE[17440] netsock2.c: == Using SIP RTP TOS bits 184 [Oct 24 09:03:45] VERBOSE[17440] netsock2.c: == Using SIP RTP CoS mark 5 [Oct 24 09:03:45] NOTICE[17440] app_dial.c: Not accepting call completion offers from call-forward recipient SIP/x.x.x.31:5065-00000002 [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: <--- Transmitting (NAT) to x.x.x.149:5060 ---> SIP/2.0 181 Call is being forwarded Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bKbddb8ec931B745E;received=x.x.x.149;rport=5060 From: "John Smith" ;tag=189C9E06-F1F58017 To: ;tag=as06804e2e Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 CSeq: 2 INVITE Server: Asterisk PBX 1.8.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Diversion: ;reason=unconditional Content-Length: 0 <------------> [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Audio is at 5060 [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Reliably Transmitting (no NAT) to x.x.x.31:5065: INVITE sip:3300@x.x.x.31:5065 SIP/2.0 Via: SIP/2.0/TCP x.x.x.17:5060;branch=z9hG4bK219ca00e Max-Forwards: 70 From: "John Smith" ;tag=as2eae9af5 To: Contact: Call-ID: 4137dd4c331b558645ba93ab23738a33@voip.mydomain.com CSeq: 102 INVITE User-Agent: Asterisk PBX 1.8.0 Date: Sun, 24 Oct 2010 13:03:45 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Diversion: ;reason=unconditional Content-Type: application/sdp Content-Length: 252 v=0 o=root 618441008 618441008 IN IP4 x.x.x.17 s=Asterisk PBX 1.8.0 c=IN IP4 x.x.x.17 t=0 0 m=audio 10096 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=ptime:20 a=sendrecv --- [Oct 24 09:03:45] VERBOSE[17441] chan_sip.c: Transmitting (no NAT) to x.x.x.31:5060: ACK sip:3300@x.x.x.31:5060 SIP/2.0 Via: SIP/2.0/TCP x.x.x.17:5060;branch=z9hG4bK62e7012d Max-Forwards: 70 From: "John Smith" ;tag=as1da7b780 To: ;tag=d823c5636 Contact: Call-ID: 3568167a3902d35b5f4119fa551d9813@voip.mydomain.com CSeq: 102 ACK User-Agent: Asterisk PBX 1.8.0 Content-Length: 0 --- [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: <--- SIP read from TCP:x.x.x.31:5065 ---> SIP/2.0 100 Trying FROM: "John Smith";tag=as2eae9af5 TO: CSEQ: 102 INVITE CALL-ID: 4137dd4c331b558645ba93ab23738a33@voip.mydomain.com VIA: SIP/2.0/TCP x.x.x.17:5060;branch=z9hG4bK219ca00e CONTENT-LENGTH: 0 <-------------> [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: --- (7 headers 0 lines) --- [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: <--- SIP read from TCP:x.x.x.31:5065 ---> SIP/2.0 180 Ringing FROM: "John Smith";tag=as2eae9af5 TO: ;tag=9635534993;epid=293064B3F3 CSEQ: 102 INVITE CALL-ID: 4137dd4c331b558645ba93ab23738a33@voip.mydomain.com VIA: SIP/2.0/TCP x.x.x.17:5060;branch=z9hG4bK219ca00e CONTACT: ;automata;actor="attendant";text;audio;video;image CONTENT-LENGTH: 0 ALLOW: UPDATE ALLOW: PRACK P-ASSERTED-IDENTITY: SERVER: RTCC/3.5.0.0 MSExchangeUM/14.01.0180.002 <-------------> [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: --- (12 headers 0 lines) --- [Oct 24 09:03:45] VERBOSE[17440] app_dial.c: -- SIP/x.x.x.31:5065-00000002 is ringing [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: <--- Transmitting (NAT) to x.x.x.149:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bKbddb8ec931B745E;received=x.x.x.149;rport=5060 From: "John Smith" ;tag=189C9E06-F1F58017 To: ;tag=as06804e2e Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 CSeq: 2 INVITE Server: Asterisk PBX 1.8.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: <--- SIP read from TCP:x.x.x.31:5065 ---> SIP/2.0 200 OK FROM: "John Smith";tag=as2eae9af5 TO: ;tag=9635534993;epid=293064B3F3 CSEQ: 102 INVITE CALL-ID: 4137dd4c331b558645ba93ab23738a33@voip.mydomain.com VIA: SIP/2.0/TCP x.x.x.17:5060;branch=z9hG4bK219ca00e CONTACT: ;automata;actor="attendant";text;audio;video;image CONTENT-LENGTH: 290 PRIORITY: Normal SUPPORTED: Replaces SUPPORTED: timer SUPPORTED: 100rel CONTENT-TYPE: application/sdp ALLOW: ACK P-ASSERTED-IDENTITY: SERVER: RTCC/3.5.0.0 MSExchangeUM/14.01.0180.002 Content-ID: 9e9bef55-c40b-4bbf-8723-9432daf6b6f2 Allow: CANCEL,BYE,INVITE,MESSAGE,INFO,SERVICE,OPTIONS,BENOTIFY,NOTIFY,PRACK,UPDATE Session-Expires: 1800;refresher=uac Min-SE: 90 v=0 o=- 38 0 IN IP4 x.x.x.31 s=session c=IN IP4 x.x.x.31 b=CT:1000 t=0 0 m=audio 1066 RTP/AVP 0 8 101 c=IN IP4 x.x.x.31 a=rtcp:1067 a=sendrecv a=label:main-audio a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16,36 a=ptime:20 <-------------> [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: --- (20 headers 16 lines) --- [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: Found RTP audio format 0 [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: Found RTP audio format 8 [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: Found RTP audio format 101 [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: Found audio description format PCMU for ID 0 [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: Found audio description format PCMA for ID 8 [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: Found audio description format telephone-event for ID 101 [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: Peer audio RTP is at port x.x.x.31:1066 [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: list_route: hop: [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: set_destination: Parsing for address/port to send to [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: set_destination: set destination to x.x.x.31:5065 [Oct 24 09:03:45] VERBOSE[17442] chan_sip.c: Transmitting (no NAT) to x.x.x.31:5065: ACK sip:exch.testdev.local:5065;transport=Tcp;maddr=x.x.x.31 SIP/2.0 Via: SIP/2.0/TCP x.x.x.17:5060;branch=z9hG4bK29dce99a Max-Forwards: 70 From: "John Smith" ;tag=as2eae9af5 To: ;tag=9635534993 Contact: Call-ID: 4137dd4c331b558645ba93ab23738a33@voip.mydomain.com CSeq: 102 ACK User-Agent: Asterisk PBX 1.8.0 Content-Length: 0 --- [Oct 24 09:03:45] VERBOSE[17440] app_dial.c: -- SIP/x.x.x.31:5065-00000002 answered SIP/1050-00000000 [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Audio is at 5060 [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Oct 24 09:03:45] VERBOSE[17440] chan_sip.c: <--- Reliably Transmitting (NAT) to x.x.x.149:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bKbddb8ec931B745E;received=x.x.x.149;rport=5060 From: "John Smith" ;tag=189C9E06-F1F58017 To: ;tag=as06804e2e Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 CSeq: 2 INVITE Server: Asterisk PBX 1.8.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 252 v=0 o=root 335951233 335951233 IN IP4 x.x.x.17 s=Asterisk PBX 1.8.0 c=IN IP4 x.x.x.17 t=0 0 m=audio 10134 RTP/AVP 0 8 127 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:127 telephone-event/8000 a=fmtp:127 0-16 a=ptime:20 a=sendrecv <------------> [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: Really destroying SIP dialog '3568167a3902d35b5f4119fa551d9813@voip.mydomain.com' Method: INVITE [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: <--- SIP read from UDP:x.x.x.149:5060 ---> ACK sip:3300@x.x.x.17:5060 SIP/2.0 Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bKa4e6a1c52BA8F2AA From: "John Smith" ;tag=189C9E06-F1F58017 To: ;tag=as06804e2e CSeq: 2 ACK Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.2.3.1734 Accept-Language: en Max-Forwards: 70 Content-Length: 0 <-------------> [Oct 24 09:03:45] VERBOSE[17424] chan_sip.c: --- (12 headers 0 lines) --- [Oct 24 09:03:48] VERBOSE[17424] chan_sip.c: <--- SIP read from UDP:x.x.x.149:5060 ---> BYE sip:3300@x.x.x.17:5060 SIP/2.0 Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bK25d0f8ebDB454858 From: "John Smith" ;tag=189C9E06-F1F58017 To: ;tag=as06804e2e CSeq: 3 BYE Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 Contact: User-Agent: PolycomSoundPointIP-SPIP_550-UA/3.2.3.1734 Accept-Language: en Authorization: Digest username="1050", realm="asterisk", nonce="29fff2aa", uri="sip:3300@voip.mydomain.com:5060;user=phone", response="8546466b1010180ebf6703cb0b5aec08", algorithm=MD5 Max-Forwards: 70 Content-Length: 0 <-------------> [Oct 24 09:03:48] VERBOSE[17424] chan_sip.c: --- (12 headers 0 lines) --- [Oct 24 09:03:48] VERBOSE[17424] chan_sip.c: Sending to x.x.x.149:5060 (NAT) [Oct 24 09:03:48] VERBOSE[17424] chan_sip.c: Scheduling destruction of SIP dialog '377f46d2-e33a33f3-b78458c0@x.x.x.149' in 6400 ms (Method: BYE) [Oct 24 09:03:48] VERBOSE[17424] chan_sip.c: <--- Transmitting (NAT) to x.x.x.149:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP x.x.x.149:5060;branch=z9hG4bK25d0f8ebDB454858;received=x.x.x.149;rport=5060 From: "John Smith" ;tag=189C9E06-F1F58017 To: ;tag=as06804e2e Call-ID: 377f46d2-e33a33f3-b78458c0@x.x.x.149 CSeq: 3 BYE Server: Asterisk PBX 1.8.0 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [Oct 24 09:03:48] VERBOSE[17440] pbx.c: -- Executing [h@macro-dialout-trunk:1] Macro("SIP/1050-00000000", "hangupcall,") in new stack [Oct 24 09:03:48] VERBOSE[17440] pbx.c: -- Executing [s@macro-hangupcall:1] GotoIf("SIP/1050-00000000", "1?skiprg") in new stack [Oct 24 09:03:48] VERBOSE[17440] pbx.c: -- Goto (macro-hangupcall,s,4) [Oct 24 09:03:48] VERBOSE[17440] pbx.c: -- Executing [s@macro-hangupcall:4] GotoIf("SIP/1050-00000000", "1?skipblkvm") in new stack [Oct 24 09:03:48] VERBOSE[17440] pbx.c: -- Goto (macro-hangupcall,s,7) [Oct 24 09:03:48] VERBOSE[17440] pbx.c: -- Executing [s@macro-hangupcall:7] GotoIf("SIP/1050-00000000", "1?theend") in new stack [Oct 24 09:03:48] VERBOSE[17440] pbx.c: -- Goto (macro-hangupcall,s,9) [Oct 24 09:03:48] VERBOSE[17440] pbx.c: -- Executing [s@macro-hangupcall:9] Hangup("SIP/1050-00000000", "") in new stack [Oct 24 09:03:48] VERBOSE[17440] app_macro.c: == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/1050-00000000' in macro 'hangupcall' [Oct 24 09:03:48] VERBOSE[17440] chan_sip.c: Scheduling destruction of SIP dialog '4137dd4c331b558645ba93ab23738a33@voip.mydomain.com' in 32000 ms (Method: INVITE) [Oct 24 09:03:48] VERBOSE[17440] chan_sip.c: set_destination: Parsing for address/port to send to [Oct 24 09:03:48] VERBOSE[17440] chan_sip.c: set_destination: set destination to x.x.x.31:5065 [Oct 24 09:03:48] VERBOSE[17440] chan_sip.c: Reliably Transmitting (no NAT) to x.x.x.31:5065: BYE sip:exch.testdev.local:5065;transport=Tcp;maddr=x.x.x.31 SIP/2.0 Via: SIP/2.0/TCP x.x.x.17:5060;branch=z9hG4bK2f75dc05 Max-Forwards: 70 From: "John Smith" ;tag=as2eae9af5 To: ;tag=9635534993 Call-ID: 4137dd4c331b558645ba93ab23738a33@voip.mydomain.com CSeq: 103 BYE User-Agent: Asterisk PBX 1.8.0 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- [Oct 24 09:03:48] VERBOSE[17440] app_macro.c: == Spawn extension (macro-dialout-trunk, s, 19) exited non-zero on 'SIP/1050-00000000' in macro 'dialout-trunk' [Oct 24 09:03:48] VERBOSE[17440] pbx.c: == Spawn extension (from-internal, 3300, 5) exited non-zero on 'SIP/1050-00000000' [Oct 24 09:03:48] VERBOSE[17442] chan_sip.c: <--- SIP read from TCP:x.x.x.31:5065 ---> SIP/2.0 200 OK FROM: "John Smith";tag=as2eae9af5 TO: ;tag=9635534993;epid=293064B3F3 CSEQ: 103 BYE CALL-ID: 4137dd4c331b558645ba93ab23738a33@voip.mydomain.com VIA: SIP/2.0/TCP x.x.x.17:5060;branch=z9hG4bK2f75dc05 CONTENT-LENGTH: 0 SERVER: RTCC/3.5.0.0 MSExchangeUM/14.01.0180.002 <-------------> [Oct 24 09:03:48] VERBOSE[17442] chan_sip.c: --- (8 headers 0 lines) --- [Oct 24 09:03:49] VERBOSE[17424] chan_sip.c: Really destroying SIP dialog '4137dd4c331b558645ba93ab23738a33@voip.mydomain.com' Method: INVITE [Oct 24 09:03:50] VERBOSE[17424] chan_sip.c: Really destroying SIP dialog '6040db1c2585f921320c11002bcc9295@voip.mydomain.com' Method: REGISTER [Oct 24 09:03:50] VERBOSE[17424] chan_sip.c: Really destroying SIP dialog '188f8c4d308b6a8347a6db227389b044@voip.mydomain.com' Method: REGISTER [Oct 24 09:03:50] VERBOSE[17439] asterisk.c: -- Remote UNIX connection disconnected [Oct 24 09:03:54] VERBOSE[17424] chan_sip.c: Really destroying SIP dialog '377f46d2-e33a33f3-b78458c0@x.x.x.149' Method: BYE