[Jul 22 18:39:33] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.165:5060 ---> INVITE sip:4@10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK36e8d7ef0612102c From: "TEST2" ;tag=e6fd3af459f657f6 To: Contact: Supported: replaces, timer, path Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63419 INVITE User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Type: application/sdp Content-Length: 408 v=0 o=4063 8000 8000 IN IP4 10.215.146.165 s=SIP Call c=IN IP4 10.215.146.165 t=0 0 m=audio 5034 RTP/AVP 0 8 4 18 2 97 9 3 101 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:9 G722/8000 a=rtpmap:3 GSM/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 <-------------> [Jul 22 18:39:33] VERBOSE[1105] logger.c: --- (13 headers 19 lines) --- [Jul 22 18:39:33] VERBOSE[1105] logger.c: Sending to 10.215.146.165 : 5060 (no NAT) [Jul 22 18:39:33] VERBOSE[1105] logger.c: Using INVITE request as basis request - b4b937b9796cb53f@10.215.146.165 [Jul 22 18:39:33] VERBOSE[1105] logger.c: <--- Reliably Transmitting (NAT) to 10.215.146.165:5060 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK36e8d7ef0612102c;received=10.215.146.165 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63419 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="6bf87832" Content-Length: 0 <------------> [Jul 22 18:39:33] VERBOSE[1105] logger.c: Scheduling destruction of SIP dialog 'b4b937b9796cb53f@10.215.146.165' in 32000 ms (Method: INVITE) [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found user '4063' [Jul 22 18:39:33] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.165:5060 ---> ACK sip:4@10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK36e8d7ef0612102c From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Contact: Supported: path Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63419 ACK User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Length: 0 <-------------> [Jul 22 18:39:33] VERBOSE[1105] logger.c: --- (12 headers 0 lines) --- [Jul 22 18:39:33] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.165:5060 ---> INVITE sip:4@10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK557518b861f1bee7 From: "TEST2" ;tag=e6fd3af459f657f6 To: Contact: Supported: replaces, timer, path Proxy-Authorization: Digest username="4063", realm="asterisk", algorithm=MD5, uri="sip:4@10.215.147.112", nonce="6bf87832", response="9f9e3474bb77e1f0ee4d846d23daaf05" Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63420 INVITE User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Type: application/sdp Content-Length: 408 v=0 o=4063 8000 8001 IN IP4 10.215.146.165 s=SIP Call c=IN IP4 10.215.146.165 t=0 0 m=audio 5034 RTP/AVP 0 8 4 18 2 97 9 3 101 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:9 G722/8000 a=rtpmap:3 GSM/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 <-------------> [Jul 22 18:39:33] VERBOSE[1105] logger.c: --- (14 headers 19 lines) --- [Jul 22 18:39:33] VERBOSE[1105] logger.c: Sending to 10.215.146.165 : 5060 (NAT) [Jul 22 18:39:33] VERBOSE[1105] logger.c: Using INVITE request as basis request - b4b937b9796cb53f@10.215.146.165 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found user '4063' [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found RTP audio format 0 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found RTP audio format 8 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found RTP audio format 4 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found RTP audio format 18 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found RTP audio format 2 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found RTP audio format 97 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found RTP audio format 9 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found RTP audio format 3 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found RTP audio format 101 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Peer audio RTP is at port 10.215.146.165:5034 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found audio description format PCMU for ID 0 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found audio description format PCMA for ID 8 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found audio description format G723 for ID 4 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found audio description format G729 for ID 18 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found audio description format G726-32 for ID 2 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found audio description format iLBC for ID 97 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found audio description format G722 for ID 9 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found audio description format GSM for ID 3 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Found audio description format telephone-event for ID 101 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Capabilities: us - 0x2 (gsm), peer - audio=0x1d0f (g723|gsm|ulaw|alaw|g726|g729|ilbc|g722)/video=0x0 (nothing), combined - 0x2 (gsm) [Jul 22 18:39:33] VERBOSE[1105] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Jul 22 18:39:33] VERBOSE[1105] logger.c: Peer audio RTP is at port 10.215.146.165:5034 [Jul 22 18:39:33] DEBUG[1105] chan_sip.c: Call from peer '4063' is 1 out of 50 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Looking for 4 in from-internal (domain 10.215.147.112) [Jul 22 18:39:33] VERBOSE[1105] logger.c: <--- Reliably Transmitting (NAT) to 10.215.146.165:5060 ---> SIP/2.0 484 Address Incomplete Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK557518b861f1bee7;received=10.215.146.165 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63420 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Jul 22 18:39:33] DEBUG[1105] chan_sip.c: Call from peer '4063' removed from call limit 50 [Jul 22 18:39:33] VERBOSE[1105] logger.c: Scheduling destruction of SIP dialog 'b4b937b9796cb53f@10.215.146.165' in 32000 ms (Method: INVITE) [Jul 22 18:39:33] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.165:5060 ---> ACK sip:4@10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK557518b861f1bee7 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Contact: Supported: path Proxy-Authorization: Digest username="4063", realm="asterisk", algorithm=MD5, uri="sip:4@10.215.147.112", nonce="6bf87832", response="9f9e3474bb77e1f0ee4d846d23daaf05" Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63420 ACK User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Length: 0 <-------------> [Jul 22 18:39:33] VERBOSE[1105] logger.c: --- (13 headers 0 lines) --- [Jul 22 18:39:34] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.165:5060 ---> INVITE sip:40@10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK07abb2dd9ce69bb6 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Contact: Supported: replaces, timer, path Proxy-Authorization: Digest username="4063", realm="asterisk", algorithm=MD5, uri="sip:40@10.215.147.112", nonce="6bf87832", response="4dccca0d767f1daa2a2d5c777b7bc574" Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63421 INVITE User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Type: application/sdp Content-Length: 408 v=0 o=4063 8000 8002 IN IP4 10.215.146.165 s=SIP Call c=IN IP4 10.215.146.165 t=0 0 m=audio 5036 RTP/AVP 0 8 4 18 2 97 9 3 101 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:9 G722/8000 a=rtpmap:3 GSM/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 <-------------> [Jul 22 18:39:34] VERBOSE[1105] logger.c: --- (14 headers 19 lines) --- [Jul 22 18:39:34] VERBOSE[1105] logger.c: Sending to 10.215.146.165 : 5060 (NAT) [Jul 22 18:39:34] VERBOSE[1105] logger.c: Using INVITE request as basis request - b4b937b9796cb53f@10.215.146.165 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found user '4063' [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 0 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 8 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 4 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 18 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 2 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 97 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 9 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 3 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 101 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Peer audio RTP is at port 10.215.146.165:5036 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format PCMU for ID 0 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format PCMA for ID 8 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format G723 for ID 4 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format G729 for ID 18 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format G726-32 for ID 2 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format iLBC for ID 97 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format G722 for ID 9 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format GSM for ID 3 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format telephone-event for ID 101 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Capabilities: us - 0x2 (gsm), peer - audio=0x1d0f (g723|gsm|ulaw|alaw|g726|g729|ilbc|g722)/video=0x0 (nothing), combined - 0x2 (gsm) [Jul 22 18:39:34] VERBOSE[1105] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Jul 22 18:39:34] VERBOSE[1105] logger.c: Peer audio RTP is at port 10.215.146.165:5036 [Jul 22 18:39:34] DEBUG[1105] chan_sip.c: Call from peer '4063' is 1 out of 50 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Looking for 40 in from-internal (domain 10.215.147.112) [Jul 22 18:39:34] VERBOSE[1105] logger.c: <--- Reliably Transmitting (NAT) to 10.215.146.165:5060 ---> SIP/2.0 484 Address Incomplete Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK07abb2dd9ce69bb6;received=10.215.146.165 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63421 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Jul 22 18:39:34] DEBUG[1105] chan_sip.c: Call from peer '4063' removed from call limit 50 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Scheduling destruction of SIP dialog 'b4b937b9796cb53f@10.215.146.165' in 32000 ms (Method: INVITE) [Jul 22 18:39:34] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.165:5060 ---> ACK sip:40@10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK07abb2dd9ce69bb6 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Contact: Supported: path Proxy-Authorization: Digest username="4063", realm="asterisk", algorithm=MD5, uri="sip:40@10.215.147.112", nonce="6bf87832", response="4dccca0d767f1daa2a2d5c777b7bc574" Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63421 ACK User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Length: 0 <-------------> [Jul 22 18:39:34] VERBOSE[1105] logger.c: --- (13 headers 0 lines) --- [Jul 22 18:39:34] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.165:5060 ---> INVITE sip:406@10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK14ed14cf94bb3c25 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Contact: Supported: replaces, timer, path Proxy-Authorization: Digest username="4063", realm="asterisk", algorithm=MD5, uri="sip:406@10.215.147.112", nonce="6bf87832", response="c872852e52f844cf166709ce5c7f8c97" Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63422 INVITE User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Type: application/sdp Content-Length: 408 v=0 o=4063 8000 8003 IN IP4 10.215.146.165 s=SIP Call c=IN IP4 10.215.146.165 t=0 0 m=audio 5038 RTP/AVP 0 8 4 18 2 97 9 3 101 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:9 G722/8000 a=rtpmap:3 GSM/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 <-------------> [Jul 22 18:39:34] VERBOSE[1105] logger.c: --- (14 headers 19 lines) --- [Jul 22 18:39:34] VERBOSE[1105] logger.c: Sending to 10.215.146.165 : 5060 (NAT) [Jul 22 18:39:34] VERBOSE[1105] logger.c: Using INVITE request as basis request - b4b937b9796cb53f@10.215.146.165 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found user '4063' [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 0 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 8 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 4 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 18 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 2 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 97 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 9 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 3 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found RTP audio format 101 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Peer audio RTP is at port 10.215.146.165:5038 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format PCMU for ID 0 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format PCMA for ID 8 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format G723 for ID 4 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format G729 for ID 18 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format G726-32 for ID 2 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format iLBC for ID 97 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format G722 for ID 9 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format GSM for ID 3 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Found audio description format telephone-event for ID 101 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Capabilities: us - 0x2 (gsm), peer - audio=0x1d0f (g723|gsm|ulaw|alaw|g726|g729|ilbc|g722)/video=0x0 (nothing), combined - 0x2 (gsm) [Jul 22 18:39:34] VERBOSE[1105] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Jul 22 18:39:34] VERBOSE[1105] logger.c: Peer audio RTP is at port 10.215.146.165:5038 [Jul 22 18:39:34] DEBUG[1105] chan_sip.c: Call from peer '4063' is 1 out of 50 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Looking for 406 in from-internal (domain 10.215.147.112) [Jul 22 18:39:34] VERBOSE[1105] logger.c: <--- Reliably Transmitting (NAT) to 10.215.146.165:5060 ---> SIP/2.0 484 Address Incomplete Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK14ed14cf94bb3c25;received=10.215.146.165 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63422 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Jul 22 18:39:34] DEBUG[1105] chan_sip.c: Call from peer '4063' removed from call limit 50 [Jul 22 18:39:34] VERBOSE[1105] logger.c: Scheduling destruction of SIP dialog 'b4b937b9796cb53f@10.215.146.165' in 32000 ms (Method: INVITE) [Jul 22 18:39:34] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.165:5060 ---> ACK sip:406@10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK14ed14cf94bb3c25 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Contact: Supported: path Proxy-Authorization: Digest username="4063", realm="asterisk", algorithm=MD5, uri="sip:406@10.215.147.112", nonce="6bf87832", response="c872852e52f844cf166709ce5c7f8c97" Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63422 ACK User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Length: 0 <-------------> [Jul 22 18:39:34] VERBOSE[1105] logger.c: --- (13 headers 0 lines) --- [Jul 22 18:39:35] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.165:5060 ---> INVITE sip:4064@10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK64bfd7a474ab2fcd From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Contact: Supported: replaces, timer, path Proxy-Authorization: Digest username="4063", realm="asterisk", algorithm=MD5, uri="sip:4064@10.215.147.112", nonce="6bf87832", response="9dbd5b5a9126456b8117d8bb785ceb3e" Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63423 INVITE User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Type: application/sdp Content-Length: 408 v=0 o=4063 8000 8004 IN IP4 10.215.146.165 s=SIP Call c=IN IP4 10.215.146.165 t=0 0 m=audio 5040 RTP/AVP 0 8 4 18 2 97 9 3 101 a=sendrecv a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:4 G723/8000 a=rtpmap:18 G729/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:9 G722/8000 a=rtpmap:3 GSM/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 <-------------> [Jul 22 18:39:35] VERBOSE[1105] logger.c: --- (14 headers 19 lines) --- [Jul 22 18:39:35] VERBOSE[1105] logger.c: Sending to 10.215.146.165 : 5060 (NAT) [Jul 22 18:39:35] VERBOSE[1105] logger.c: Using INVITE request as basis request - b4b937b9796cb53f@10.215.146.165 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found user '4063' [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found RTP audio format 0 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found RTP audio format 8 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found RTP audio format 4 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found RTP audio format 18 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found RTP audio format 2 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found RTP audio format 97 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found RTP audio format 9 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found RTP audio format 3 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found RTP audio format 101 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Peer audio RTP is at port 10.215.146.165:5040 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found audio description format PCMU for ID 0 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found audio description format PCMA for ID 8 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found audio description format G723 for ID 4 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found audio description format G729 for ID 18 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found audio description format G726-32 for ID 2 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found audio description format iLBC for ID 97 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found audio description format G722 for ID 9 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found audio description format GSM for ID 3 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Found audio description format telephone-event for ID 101 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Capabilities: us - 0x2 (gsm), peer - audio=0x1d0f (g723|gsm|ulaw|alaw|g726|g729|ilbc|g722)/video=0x0 (nothing), combined - 0x2 (gsm) [Jul 22 18:39:35] VERBOSE[1105] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Jul 22 18:39:35] VERBOSE[1105] logger.c: Peer audio RTP is at port 10.215.146.165:5040 [Jul 22 18:39:35] DEBUG[1105] chan_sip.c: Call from peer '4063' is 1 out of 50 [Jul 22 18:39:35] VERBOSE[1105] logger.c: Looking for 4064 in from-internal (domain 10.215.147.112) [Jul 22 18:39:35] VERBOSE[1105] logger.c: list_route: hop: [Jul 22 18:39:35] VERBOSE[1105] logger.c: <--- Transmitting (NAT) to 10.215.146.165:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK64bfd7a474ab2fcd;received=10.215.146.165 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63423 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [4064@from-internal:1] Macro("SIP/4063-0848ca58", "exten-vm|novm|4064") in new stack [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-exten-vm:1] Macro("SIP/4063-0848ca58", "user-callerid") in new stack [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:1] Set("SIP/4063-0848ca58", "AMPUSER=4063") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:2] GotoIf("SIP/4063-0848ca58", "0?report") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: GotoIf [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:3] ExecIf("SIP/4063-0848ca58", "1|Set|REALCALLERIDNUM=4063") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: ExecIf [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:4] Set("SIP/4063-0848ca58", "AMPUSER=4063") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:5] Set("SIP/4063-0848ca58", "AMPUSERCIDNAME=INF TEST2") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:6] GotoIf("SIP/4063-0848ca58", "0?report") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: GotoIf [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:7] Set("SIP/4063-0848ca58", "AMPUSERCID=4063") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:8] Set("SIP/4063-0848ca58", "CALLERID(all)="INF TEST2" <4063>") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:9] Set("SIP/4063-0848ca58", "REALCALLERIDNUM=4063") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:10] ExecIf("SIP/4063-0848ca58", "1|Set|CHANNEL(language)=es") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: ExecIf [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Last app: Set|CHANNEL(language)=es [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:11] GotoIf("SIP/4063-0848ca58", "0?continue") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: GotoIf [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:12] Set("SIP/4063-0848ca58", "__TTL=64") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:13] GotoIf("SIP/4063-0848ca58", "1?continue") in new stack [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Goto (macro-user-callerid,s,20) [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: GotoIf [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-user-callerid:20] NoOp("SIP/4063-0848ca58", "Using CallerID "INF TEST2" <4063>") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Noop [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Macro [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-exten-vm:2] Set("SIP/4063-0848ca58", "RingGroupMethod=none") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-exten-vm:3] Set("SIP/4063-0848ca58", "VMBOX=novm") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-exten-vm:4] Set("SIP/4063-0848ca58", "EXTTOCALL=4064") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] DEBUG[4439] func_db.c: DB: CFU/4064 not found in database. [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-exten-vm:5] Set("SIP/4063-0848ca58", "CFUEXT=") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] DEBUG[4439] func_db.c: DB: CFB/4064 not found in database. [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-exten-vm:6] Set("SIP/4063-0848ca58", "CFBEXT=") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-exten-vm:7] Set("SIP/4063-0848ca58", "RT=""") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Set [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-exten-vm:8] Macro("SIP/4063-0848ca58", "record-enable|4064|IN") in new stack [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/4063-0848ca58", "1?check") in new stack [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Goto (macro-record-enable,s,4) [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: GotoIf [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-record-enable:4] AGI("SIP/4063-0848ca58", "recordingcheck|20090722-183935|1248280775.7") in new stack [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck [Jul 22 18:39:35] VERBOSE[4439] logger.c: recordingcheck|20090722-183935|1248280775.7: Inbound recording not enabled [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- AGI Script recordingcheck completed, returning 0 [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: AGI [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-record-enable:5] MacroExit("SIP/4063-0848ca58", "") in new stack [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: Macro [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-exten-vm:9] Macro("SIP/4063-0848ca58", "dial||tTwW|4064") in new stack [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-dial:1] GotoIf("SIP/4063-0848ca58", "1?dial") in new stack [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Goto (macro-dial,s,3) [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: GotoIf [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-dial:3] AGI("SIP/4063-0848ca58", "dialparties.agi") in new stack [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi [Jul 22 18:39:35] VERBOSE[4439] logger.c: dialparties.agi: Starting New Dialparties.agi [Jul 22 18:39:35] VERBOSE[4444] logger.c: == Parsing '/etc/asterisk/manager.conf': [Jul 22 18:39:35] VERBOSE[4444] logger.c: Found [Jul 22 18:39:35] VERBOSE[4444] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': [Jul 22 18:39:35] VERBOSE[4444] logger.c: Found [Jul 22 18:39:35] VERBOSE[4444] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': [Jul 22 18:39:35] VERBOSE[4444] logger.c: Found [Jul 22 18:39:35] VERBOSE[4444] logger.c: == Manager 'informatica' logged on from 127.0.0.1 [Jul 22 18:39:35] VERBOSE[4439] logger.c: dialparties.agi: Caller ID name is 'INF TEST2' number is '4063' [Jul 22 18:39:35] VERBOSE[4439] logger.c: dialparties.agi: USE_CONFIRMATION: 'FALSE' [Jul 22 18:39:35] VERBOSE[4439] logger.c: dialparties.agi: RINGGROUP_INDEX: '' [Jul 22 18:39:35] VERBOSE[4439] logger.c: dialparties.agi: Methodology of ring is 'none' [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- dialparties.agi: Added extension 4064 to extension map [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- dialparties.agi: VIERI: cfignore= cidnum=4063 cf= realcalleridnum=4063 blindtransfer= [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- dialparties.agi: Extension 4064 cf is disabled [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- dialparties.agi: Extension 4064 do not disturb is disabled [Jul 22 18:39:35] VERBOSE[4439] logger.c: > dialparties.agi: extnum 4064 has: cw: 0; hascfb: 0 [] hascfu: 0 [] [Jul 22 18:39:35] VERBOSE[4439] logger.c: > dialparties.agi: ExtensionState: 0 [Jul 22 18:39:35] VERBOSE[4439] logger.c: dialparties.agi: Extension 4064 has ExtensionState: 0 [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- dialparties.agi: Checking CW and CFB status for extension 4064 [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- dialparties.agi: dbset CALLTRACE/4064 to 4063 [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- dialparties.agi: Filtered ARG3: 4064 [Jul 22 18:39:35] VERBOSE[4444] logger.c: == Manager 'informatica' logged off from 127.0.0.1 [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- AGI Script dialparties.agi completed, returning 0 [Jul 22 18:39:35] DEBUG[4439] app_macro.c: Executed application: AGI [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Executing [s@macro-dial:7] Dial("SIP/4063-0848ca58", "SIP/4064||tTwW") in new stack [Jul 22 18:39:35] DEBUG[4439] chan_sip.c: Call to peer '4064' is 1 out of 50 [Jul 22 18:39:35] VERBOSE[4439] logger.c: Audio is at 10.215.147.112 port 16270 [Jul 22 18:39:35] VERBOSE[4439] logger.c: Adding codec 0x2 (gsm) to SDP [Jul 22 18:39:35] VERBOSE[4439] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Jul 22 18:39:35] VERBOSE[4439] logger.c: Reliably Transmitting (NAT) to 10.215.146.175:5060: INVITE sip:4064@10.215.146.175:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.215.147.112:5060;branch=z9hG4bK25e50398;rport From: "INF TEST2" ;tag=as1b2e481c To: Contact: Call-ID: 052fe1ec3b1a0669227174d30085ccb6@10.215.147.112 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 22 Jul 2009 16:39:35 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 241 v=0 o=root 1085 1085 IN IP4 10.215.147.112 s=session c=IN IP4 10.215.147.112 t=0 0 m=audio 16270 RTP/AVP 3 101 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- Called 4064 [Jul 22 18:39:35] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.175:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.215.147.112:5060;branch=z9hG4bK25e50398;rport From: "INF TEST2" ;tag=as1b2e481c To: Call-ID: 052fe1ec3b1a0669227174d30085ccb6@10.215.147.112 CSeq: 102 INVITE User-Agent: Grandstream GXP280 1.1.6.46 Content-Length: 0 <-------------> [Jul 22 18:39:35] VERBOSE[1105] logger.c: --- (8 headers 0 lines) --- [Jul 22 18:39:35] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.175:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.215.147.112:5060;branch=z9hG4bK25e50398;rport From: "INF TEST2" ;tag=as1b2e481c To: ;tag=8ebfcbfbe1b4db53 Call-ID: 052fe1ec3b1a0669227174d30085ccb6@10.215.147.112 CSeq: 102 INVITE User-Agent: Grandstream GXP280 1.1.6.46 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Length: 0 <-------------> [Jul 22 18:39:35] VERBOSE[1105] logger.c: --- (10 headers 0 lines) --- [Jul 22 18:39:35] VERBOSE[4439] logger.c: -- SIP/4064-084941a8 is ringing [Jul 22 18:39:35] VERBOSE[4439] logger.c: <--- Transmitting (NAT) to 10.215.146.165:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK64bfd7a474ab2fcd;received=10.215.146.165 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63423 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 22 18:39:36] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.175:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.215.147.112:5060;branch=z9hG4bK25e50398;rport From: "INF TEST2" ;tag=as1b2e481c To: ;tag=8ebfcbfbe1b4db53 Call-ID: 052fe1ec3b1a0669227174d30085ccb6@10.215.147.112 CSeq: 102 INVITE User-Agent: Grandstream GXP280 1.1.6.46 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Type: application/sdp Supported: replaces, timer Content-Length: 214 v=0 o=4064 8000 8000 IN IP4 10.215.146.175 s=SIP Call c=IN IP4 10.215.146.175 t=0 0 m=audio 5082 RTP/AVP 3 101 a=sendrecv a=rtpmap:3 GSM/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 <-------------> [Jul 22 18:39:36] VERBOSE[1105] logger.c: --- (12 headers 11 lines) --- [Jul 22 18:39:36] VERBOSE[1105] logger.c: Found RTP audio format 3 [Jul 22 18:39:36] VERBOSE[1105] logger.c: Found RTP audio format 101 [Jul 22 18:39:36] VERBOSE[1105] logger.c: Peer audio RTP is at port 10.215.146.175:5082 [Jul 22 18:39:36] VERBOSE[1105] logger.c: Found audio description format GSM for ID 3 [Jul 22 18:39:36] VERBOSE[1105] logger.c: Found audio description format telephone-event for ID 101 [Jul 22 18:39:36] VERBOSE[1105] logger.c: Capabilities: us - 0x2 (gsm), peer - audio=0x2 (gsm)/video=0x0 (nothing), combined - 0x2 (gsm) [Jul 22 18:39:36] VERBOSE[1105] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Jul 22 18:39:36] VERBOSE[1105] logger.c: Peer audio RTP is at port 10.215.146.175:5082 [Jul 22 18:39:36] VERBOSE[1105] logger.c: list_route: hop: [Jul 22 18:39:36] DEBUG[1105] chan_sip.c: Strict routing enforced for session 052fe1ec3b1a0669227174d30085ccb6@10.215.147.112 [Jul 22 18:39:36] VERBOSE[1105] logger.c: set_destination: Parsing for address/port to send to [Jul 22 18:39:36] VERBOSE[1105] logger.c: set_destination: set destination to 10.215.146.175, port 5060 [Jul 22 18:39:36] VERBOSE[1105] logger.c: Transmitting (NAT) to 10.215.146.175:5060: ACK sip:4064@10.215.146.175:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.215.147.112:5060;branch=z9hG4bK1d61a7b3;rport From: "INF TEST2" ;tag=as1b2e481c To: ;tag=8ebfcbfbe1b4db53 Contact: Call-ID: 052fe1ec3b1a0669227174d30085ccb6@10.215.147.112 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Jul 22 18:39:36] VERBOSE[4439] logger.c: -- SIP/4064-084941a8 answered SIP/4063-0848ca58 [Jul 22 18:39:36] VERBOSE[4439] logger.c: Audio is at 10.215.147.112 port 18196 [Jul 22 18:39:36] VERBOSE[4439] logger.c: Adding codec 0x2 (gsm) to SDP [Jul 22 18:39:36] VERBOSE[4439] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Jul 22 18:39:36] VERBOSE[4439] logger.c: <--- Reliably Transmitting (NAT) to 10.215.146.165:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK64bfd7a474ab2fcd;received=10.215.146.165 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63423 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 241 v=0 o=root 1085 1085 IN IP4 10.215.147.112 s=session c=IN IP4 10.215.147.112 t=0 0 m=audio 18196 RTP/AVP 3 101 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Jul 22 18:39:36] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.165:5060 ---> ACK sip:4064@10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.165:5060;branch=z9hG4bK32e940fc1a04cfe5 From: "TEST2" ;tag=e6fd3af459f657f6 To: ;tag=as39b35b0e Contact: Supported: path Proxy-Authorization: Digest username="4063", realm="asterisk", algorithm=MD5, uri="sip:4064@10.215.147.112", nonce="6bf87832", response="9dbd5b5a9126456b8117d8bb785ceb3e" Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 63423 ACK User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Length: 0 <-------------> [Jul 22 18:39:36] VERBOSE[1105] logger.c: --- (13 headers 0 lines) --- [Jul 22 18:39:37] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.175:5060 ---> REGISTER sip:10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.175:5060;branch=z9hG4bK9f8726bd0ade09c7 From: "TEST" ;tag=e05927f0c21ff47e To: Contact: ;reg-id=1;+sip.instance="" Supported: path Authorization: Digest username="4064", realm="asterisk", algorithm=MD5, uri="sip:10.215.147.112", nonce="1437d7c2", response="885364a33d44e38846ed2c1e3bc4a56e" Call-ID: 962198707d5dcf54@10.215.146.175 CSeq: 10037 REGISTER Expires: 120 User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Length: 0 <-------------> [Jul 22 18:39:37] VERBOSE[1105] logger.c: --- (14 headers 0 lines) --- [Jul 22 18:39:37] VERBOSE[1105] logger.c: Using latest REGISTER request as basis request [Jul 22 18:39:37] VERBOSE[1105] logger.c: Sending to 10.215.146.175 : 5060 (no NAT) [Jul 22 18:39:37] VERBOSE[1105] logger.c: <--- Transmitting (NAT) to 10.215.146.175:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.215.146.175:5060;branch=z9hG4bK9f8726bd0ade09c7;received=10.215.146.175 From: "TEST" ;tag=e05927f0c21ff47e To: Call-ID: 962198707d5dcf54@10.215.146.175 CSeq: 10037 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Jul 22 18:39:37] VERBOSE[1105] logger.c: <--- Transmitting (NAT) to 10.215.146.175:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.215.146.175:5060;branch=z9hG4bK9f8726bd0ade09c7;received=10.215.146.175 From: "TEST" ;tag=e05927f0c21ff47e To: ;tag=as284b64f1 Call-ID: 962198707d5dcf54@10.215.146.175 CSeq: 10037 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="0e4892ae" Content-Length: 0 <------------> [Jul 22 18:39:37] VERBOSE[1105] logger.c: Scheduling destruction of SIP dialog '962198707d5dcf54@10.215.146.175' in 32000 ms (Method: REGISTER) [Jul 22 18:39:37] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.175:5060 ---> REGISTER sip:10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.175:5060;branch=z9hG4bKb9e63efd7cdffacb From: "TEST" ;tag=e05927f0c21ff47e To: Contact: ;reg-id=1;+sip.instance="" Supported: path Authorization: Digest username="4064", realm="asterisk", algorithm=MD5, uri="sip:10.215.147.112", nonce="0e4892ae", response="9f9ea857fcce5872a1148cc550fee7c8" Call-ID: 962198707d5dcf54@10.215.146.175 CSeq: 10038 REGISTER Expires: 120 User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Length: 0 <-------------> [Jul 22 18:39:37] VERBOSE[1105] logger.c: --- (14 headers 0 lines) --- [Jul 22 18:39:37] VERBOSE[1105] logger.c: Using latest REGISTER request as basis request [Jul 22 18:39:37] VERBOSE[1105] logger.c: Sending to 10.215.146.175 : 5060 (NAT) [Jul 22 18:39:37] VERBOSE[1105] logger.c: <--- Transmitting (NAT) to 10.215.146.175:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.215.146.175:5060;branch=z9hG4bKb9e63efd7cdffacb;received=10.215.146.175 From: "TEST" ;tag=e05927f0c21ff47e To: Call-ID: 962198707d5dcf54@10.215.146.175 CSeq: 10038 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Jul 22 18:39:37] VERBOSE[1105] logger.c: Reliably Transmitting (NAT) to 10.215.146.175:5060: OPTIONS sip:4064@10.215.146.175:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.215.147.112:5060;branch=z9hG4bK4c07cb99;rport From: "Unknown" ;tag=as4d653747 To: Contact: Call-ID: 0f4fbf366eab565131a65ca965576cd1@10.215.147.112 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 22 Jul 2009 16:39:37 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- [Jul 22 18:39:37] VERBOSE[1105] logger.c: <--- Transmitting (NAT) to 10.215.146.175:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.215.146.175:5060;branch=z9hG4bKb9e63efd7cdffacb;received=10.215.146.175 From: "TEST" ;tag=e05927f0c21ff47e To: ;tag=as284b64f1 Call-ID: 962198707d5dcf54@10.215.146.175 CSeq: 10038 REGISTER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 120 Contact: ;expires=120 Date: Wed, 22 Jul 2009 16:39:37 GMT Content-Length: 0 <------------> [Jul 22 18:39:37] VERBOSE[1105] logger.c: Scheduling destruction of SIP dialog '962198707d5dcf54@10.215.146.175' in 32000 ms (Method: REGISTER) [Jul 22 18:39:37] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.175:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.215.147.112:5060;branch=z9hG4bK4c07cb99;rport From: "Unknown" ;tag=as4d653747 To: ;tag=8ebfcbfbe1b4db53 Call-ID: 0f4fbf366eab565131a65ca965576cd1@10.215.147.112 CSeq: 102 OPTIONS User-Agent: Grandstream GXP280 1.1.6.46 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Supported: replaces, timer Content-Length: 0 <-------------> [Jul 22 18:39:37] VERBOSE[1105] logger.c: --- (11 headers 0 lines) --- [Jul 22 18:39:37] VERBOSE[4464] logger.c: == Parsing '/etc/asterisk/manager.conf': [Jul 22 18:39:37] VERBOSE[4464] logger.c: Found [Jul 22 18:39:37] VERBOSE[4464] logger.c: == Parsing '/etc/asterisk/manager_additional.conf': [Jul 22 18:39:37] VERBOSE[4464] logger.c: Found [Jul 22 18:39:37] VERBOSE[4464] logger.c: == Parsing '/etc/asterisk/manager_custom.conf': [Jul 22 18:39:37] VERBOSE[4464] logger.c: Found [Jul 22 18:39:37] VERBOSE[4464] logger.c: == Manager 'inftester' logged on from 10.215.147.112 [Jul 22 18:39:37] VERBOSE[4464] logger.c: == Manager 'inftester' logged off from 10.215.147.112 [Jul 22 18:39:38] VERBOSE[1105] logger.c: Scheduling destruction of SIP dialog '473dba2800f115362a11cf0e2c0c5f54@10.215.147.112' in 6400 ms (Method: NOTIFY) [Jul 22 18:39:38] VERBOSE[1105] logger.c: Reliably Transmitting (NAT) to 10.215.146.175:5060: NOTIFY sip:4064@10.215.146.175:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.215.147.112:5060;branch=z9hG4bK3fbc1be9;rport From: "Unknown" ;tag=as543f31a1 To: Contact: Call-ID: 473dba2800f115362a11cf0e2c0c5f54@10.215.147.112 CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 89 Messages-Waiting: no Message-Account: sip:*97@10.215.147.112 Voice-Message: 0/0 (0/0) --- [Jul 22 18:39:38] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.175:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.215.147.112:5060;branch=z9hG4bK3fbc1be9;rport From: "Unknown" ;tag=as543f31a1 To: ;tag=8ebfcbfbe1b4db53 Call-ID: 473dba2800f115362a11cf0e2c0c5f54@10.215.147.112 CSeq: 102 NOTIFY User-Agent: Grandstream GXP280 1.1.6.46 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Supported: replaces, timer Content-Length: 0 <-------------> [Jul 22 18:39:38] VERBOSE[1105] logger.c: --- (11 headers 0 lines) --- [Jul 22 18:39:38] VERBOSE[1105] logger.c: Really destroying SIP dialog '473dba2800f115362a11cf0e2c0c5f54@10.215.147.112' Method: NOTIFY [Jul 22 18:39:38] VERBOSE[1105] logger.c: Really destroying SIP dialog '0f4fbf366eab565131a65ca965576cd1@10.215.147.112' Method: OPTIONS [Jul 22 18:39:41] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.175:5060 ---> BYE sip:4063@10.215.147.112 SIP/2.0 Via: SIP/2.0/UDP 10.215.146.175:5060;branch=z9hG4bK3d286836dbcaf4c1 From: ;tag=8ebfcbfbe1b4db53 To: "INF TEST2" ;tag=as1b2e481c Supported: path Call-ID: 052fe1ec3b1a0669227174d30085ccb6@10.215.147.112 CSeq: 59272 BYE User-Agent: Grandstream GXP280 1.1.6.46 Max-Forwards: 70 Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Content-Length: 0 <-------------> [Jul 22 18:39:41] VERBOSE[1105] logger.c: --- (11 headers 0 lines) --- [Jul 22 18:39:41] VERBOSE[1105] logger.c: Sending to 10.215.146.175 : 5060 (NAT) [Jul 22 18:39:41] VERBOSE[1105] logger.c: <--- Transmitting (NAT) to 10.215.146.175:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.215.146.175:5060;branch=z9hG4bK3d286836dbcaf4c1;received=10.215.146.175 From: ;tag=8ebfcbfbe1b4db53 To: "INF TEST2" ;tag=as1b2e481c Call-ID: 052fe1ec3b1a0669227174d30085ccb6@10.215.147.112 CSeq: 59272 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Jul 22 18:39:41] VERBOSE[4439] logger.c: -- Executing [h@macro-dial:1] Macro("SIP/4063-0848ca58", "hangupcall") in new stack [Jul 22 18:39:41] VERBOSE[4439] logger.c: -- Executing [s@macro-hangupcall:1] ResetCDR("SIP/4063-0848ca58", "w") in new stack [Jul 22 18:39:41] DEBUG[4439] app_macro.c: Executed application: ResetCDR [Jul 22 18:39:41] VERBOSE[4439] logger.c: -- Executing [s@macro-hangupcall:2] NoCDR("SIP/4063-0848ca58", "") in new stack [Jul 22 18:39:41] DEBUG[4439] app_macro.c: Executed application: NoCDR [Jul 22 18:39:41] VERBOSE[4439] logger.c: -- Executing [s@macro-hangupcall:3] GotoIf("SIP/4063-0848ca58", "1?skiprg") in new stack [Jul 22 18:39:41] VERBOSE[4439] logger.c: -- Goto (macro-hangupcall,s,6) [Jul 22 18:39:41] DEBUG[4439] app_macro.c: Executed application: GotoIf [Jul 22 18:39:41] VERBOSE[4439] logger.c: -- Executing [s@macro-hangupcall:6] GotoIf("SIP/4063-0848ca58", "1?skipblkvm") in new stack [Jul 22 18:39:41] VERBOSE[4439] logger.c: -- Goto (macro-hangupcall,s,9) [Jul 22 18:39:41] DEBUG[4439] app_macro.c: Executed application: GotoIf [Jul 22 18:39:41] VERBOSE[4439] logger.c: -- Executing [s@macro-hangupcall:9] GotoIf("SIP/4063-0848ca58", "1?theend") in new stack [Jul 22 18:39:41] VERBOSE[4439] logger.c: -- Goto (macro-hangupcall,s,11) [Jul 22 18:39:41] DEBUG[4439] app_macro.c: Executed application: GotoIf [Jul 22 18:39:41] VERBOSE[4439] logger.c: -- Executing [s@macro-hangupcall:11] Hangup("SIP/4063-0848ca58", "") in new stack [Jul 22 18:39:41] VERBOSE[4439] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/4063-0848ca58' in macro 'hangupcall' [Jul 22 18:39:41] VERBOSE[4439] logger.c: == Spawn h extension (macro-dial, h, 1) exited non-zero on 'SIP/4063-0848ca58' [Jul 22 18:39:41] DEBUG[4439] chan_sip.c: Call to peer '4064' removed from call limit 50 [Jul 22 18:39:41] VERBOSE[4439] logger.c: == Spawn extension (macro-dial, s, 7) exited non-zero on 'SIP/4063-0848ca58' in macro 'dial' [Jul 22 18:39:41] VERBOSE[4439] logger.c: == Spawn extension (macro-exten-vm, s, 9) exited non-zero on 'SIP/4063-0848ca58' in macro 'exten-vm' [Jul 22 18:39:41] VERBOSE[4439] logger.c: == Spawn extension (from-internal, 4064, 1) exited non-zero on 'SIP/4063-0848ca58' [Jul 22 18:39:41] DEBUG[4439] chan_sip.c: Call from peer '4063' removed from call limit 50 [Jul 22 18:39:41] VERBOSE[4439] logger.c: Scheduling destruction of SIP dialog 'b4b937b9796cb53f@10.215.146.165' in 32000 ms (Method: ACK) [Jul 22 18:39:41] DEBUG[4439] chan_sip.c: Strict routing enforced for session b4b937b9796cb53f@10.215.146.165 [Jul 22 18:39:41] VERBOSE[4439] logger.c: set_destination: Parsing for address/port to send to [Jul 22 18:39:41] VERBOSE[4439] logger.c: set_destination: set destination to 10.215.146.165, port 5060 [Jul 22 18:39:41] VERBOSE[4439] logger.c: Reliably Transmitting (NAT) to 10.215.146.165:5060: BYE sip:4063@10.215.146.165:5060;transport=udp SIP/2.0 Via: SIP/2.0/UDP 10.215.147.112:5060;branch=z9hG4bK2e3a0d87;rport From: ;tag=as39b35b0e To: "TEST2" ;tag=e6fd3af459f657f6 Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 102 BYE User-Agent: Asterisk PBX Max-Forwards: 70 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- [Jul 22 18:39:41] VERBOSE[1105] logger.c: <--- SIP read from 10.215.146.165:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.215.147.112:5060;branch=z9hG4bK2e3a0d87;rport From: ;tag=as39b35b0e To: "TEST2" ;tag=e6fd3af459f657f6 Call-ID: b4b937b9796cb53f@10.215.146.165 CSeq: 102 BYE User-Agent: Grandstream GXP280 1.1.6.46 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK,MESSAGE Supported: replaces, timer Content-Length: 0 <-------------> [Jul 22 18:39:41] VERBOSE[1105] logger.c: --- (11 headers 0 lines) --- [Jul 22 18:39:41] VERBOSE[1105] logger.c: SIP Response message for INCOMING dialog BYE arrived [Jul 22 18:39:42] VERBOSE[1105] logger.c: Really destroying SIP dialog '052fe1ec3b1a0669227174d30085ccb6@10.215.147.112' Method: BYE [Jul 22 18:39:42] VERBOSE[1105] logger.c: Really destroying SIP dialog 'b4b937b9796cb53f@10.215.146.165' Method: ACK