[Aug 8 11:29:37] VERBOSE[21226] config.c: == Parsing '/etc/asterisk/logger.conf': [Aug 8 11:29:37] DEBUG[21226] config.c: Parsing /etc/asterisk/logger.conf [Aug 8 11:29:37] VERBOSE[21226] config.c: == Found [Aug 8 11:29:37] VERBOSE[21226] logger.c: Asterisk Queue Logger restarted [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.22.63:5060 ---> INVITE sip:6000@10.21.0.146:5061;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bKe56418f838E66C31 From: "4709" ;tag=501CAE3D-AE03133A To: CSeq: 1 INVITE Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 Accept-Language: en Supported: 100rel,replaces Allow-Events: talk,hold,conference Max-Forwards: 70 Content-Type: application/sdp Content-Length: 292 v=0 o=- 1167931180 1167931180 IN IP4 10.13.22.63 s=Polycom IP Phone c=IN IP4 10.13.22.63 t=0 0 a=sendrecv m=audio 2246 RTP/AVP 9 0 8 18 101 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:101 telephone-event/8000 <-------------> [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 0 [ 51]: INVITE sip:6000@10.21.0.146:5061;user=phone SIP/2.0 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bKe56418f838E66C31 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 2 [ 57]: From: "4709" ;tag=501CAE3D-AE03133A [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 3 [ 37]: To: [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 4 [ 14]: CSeq: 1 INVITE [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 5 [ 47]: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 6 [ 31]: Contact: [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 7 [ 96]: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 8 [ 54]: User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 9 [ 19]: Accept-Language: en [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 10 [ 26]: Supported: 100rel,replaces [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 11 [ 34]: Allow-Events: talk,hold,conference [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 12 [ 16]: Max-Forwards: 70 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 14 [ 19]: Content-Length: 292 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 15 [ 0]: [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 0 [ 3]: v=0 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 1 [ 44]: o=- 1167931180 1167931180 IN IP4 10.13.22.63 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 2 [ 18]: s=Polycom IP Phone [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.13.22.63 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 5 [ 10]: a=sendrecv [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 6 [ 33]: m=audio 2246 RTP/AVP 9 0 8 18 101 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 7 [ 20]: a=rtpmap:9 G722/8000 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 8 [ 20]: a=rtpmap:0 PCMU/8000 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 9 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 10 [ 21]: a=rtpmap:18 G729/8000 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 11 [ 19]: a=fmtp:18 annexb=no [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: --- (15 headers 13 lines) --- [Aug 8 11:29:45] DEBUG[28074] acl.c: For destination '10.13.22.63', our source address is '10.21.0.146'. [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 10.21.0.146:5061 [Aug 8 11:29:45] VERBOSE[28074] netsock.c: == Using UDPTL CoS mark 5 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Setting NAT on UDPTL to Off [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Allocating new SIP dialog for 4bfd8dbe-e22855af-63414b54@10.13.22.63 - INVITE (No RTP) [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 8 11:29:45] DEBUG[28074] sip/reqresp_parser.c: Begin: parsing SIP "Supported: 100rel,replaces" [Aug 8 11:29:45] DEBUG[28074] sip/reqresp_parser.c: Found SIP option: -100rel- [Aug 8 11:29:45] DEBUG[28074] sip/reqresp_parser.c: Matched SIP option: 100rel [Aug 8 11:29:45] DEBUG[28074] sip/reqresp_parser.c: Found SIP option: -replaces- [Aug 8 11:29:45] DEBUG[28074] sip/reqresp_parser.c: Matched SIP option: replaces [Aug 8 11:29:45] DEBUG[28074] netsock2.c: Splitting '10.13.22.63' gives... [Aug 8 11:29:45] DEBUG[28074] netsock2.c: ...host '10.13.22.63' and port '(null)'. [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Sending to 10.13.22.63:5060 (no NAT) [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Initializing initreq for method INVITE - callid 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Using INVITE request as basis request - 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found peer '4709' for '4709' from 10.13.22.63:5060 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Setting NAT on UDPTL to Off [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: <--- Reliably Transmitting (no NAT) to 10.13.22.63:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bKe56418f838E66C31;received=10.13.22.63 From: "4709" ;tag=501CAE3D-AE03133A To: ;tag=as48a03458 Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 1 INVITE Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="09b89226" Content-Length: 0 <------------> [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #1573 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.13.22.63:5060 [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Scheduling destruction of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' in 32000 ms (Method: INVITE) [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.22.63:5060 ---> ACK sip:6000@10.21.0.146:5061 SIP/2.0 Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bKe56418f838E66C31 From: "4709" ;tag=501CAE3D-AE03133A To: ;tag=as48a03458 CSeq: 1 ACK Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 Accept-Language: en Max-Forwards: 70 Content-Length: 0 <-------------> [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 0 [ 37]: ACK sip:6000@10.21.0.146:5061 SIP/2.0 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bKe56418f838E66C31 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 2 [ 57]: From: "4709" ;tag=501CAE3D-AE03133A [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 3 [ 52]: To: ;tag=as48a03458 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 4 [ 11]: CSeq: 1 ACK [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 5 [ 47]: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 6 [ 31]: Contact: [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 7 [ 96]: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 8 [ 54]: User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 9 [ 19]: Accept-Language: en [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 10 [ 16]: Max-Forwards: 70 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 12 [ 0]: [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: --- (12 headers 0 lines) --- [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1573 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Stopping retransmission on '4bfd8dbe-e22855af-63414b54@10.13.22.63' of Response 1: Match Found [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.22.63:5060 ---> INVITE sip:6000@10.21.0.146:5061;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bKbc75a55bCE5C5AF0 From: "4709" ;tag=501CAE3D-AE03133A To: CSeq: 2 INVITE Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 Accept-Language: en Supported: 100rel,replaces Allow-Events: talk,hold,conference Authorization: Digest username="4709", realm="asterisk", nonce="09b89226", uri="sip:6000@10.21.0.146:5061;user=phone", response="5871a325d5e1e54eeb1083cab0493926", algorithm=MD5 Max-Forwards: 70 Content-Type: application/sdp Content-Length: 292 v=0 o=- 1167931180 1167931180 IN IP4 10.13.22.63 s=Polycom IP Phone c=IN IP4 10.13.22.63 t=0 0 a=sendrecv m=audio 2246 RTP/AVP 9 0 8 18 101 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:101 telephone-event/8000 <-------------> [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 0 [ 51]: INVITE sip:6000@10.21.0.146:5061;user=phone SIP/2.0 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bKbc75a55bCE5C5AF0 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 2 [ 57]: From: "4709" ;tag=501CAE3D-AE03133A [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 3 [ 37]: To: [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 4 [ 14]: CSeq: 2 INVITE [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 5 [ 47]: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 6 [ 31]: Contact: [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 7 [ 96]: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 8 [ 54]: User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 9 [ 19]: Accept-Language: en [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 10 [ 26]: Supported: 100rel,replaces [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 11 [ 34]: Allow-Events: talk,hold,conference [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 12 [177]: Authorization: Digest username="4709", realm="asterisk", nonce="09b89226", uri="sip:6000@10.21.0.146:5061;user=phone", response="5871a325d5e1e54eeb1083cab0493926", algorithm=MD5 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 13 [ 16]: Max-Forwards: 70 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 15 [ 19]: Content-Length: 292 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 16 [ 0]: [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 0 [ 3]: v=0 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 1 [ 44]: o=- 1167931180 1167931180 IN IP4 10.13.22.63 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 2 [ 18]: s=Polycom IP Phone [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.13.22.63 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 5 [ 10]: a=sendrecv [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 6 [ 33]: m=audio 2246 RTP/AVP 9 0 8 18 101 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 7 [ 20]: a=rtpmap:9 G722/8000 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 8 [ 20]: a=rtpmap:0 PCMU/8000 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 9 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 10 [ 21]: a=rtpmap:18 G729/8000 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 11 [ 19]: a=fmtp:18 annexb=no [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Body 12 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: --- (16 headers 13 lines) --- [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 8 11:29:45] DEBUG[28074] netsock2.c: Splitting '10.13.22.63' gives... [Aug 8 11:29:45] DEBUG[28074] netsock2.c: ...host '10.13.22.63' and port '(null)'. [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Sending to 10.13.22.63:5060 (no NAT) [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Initializing initreq for method INVITE - callid 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Using INVITE request as basis request - 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found peer '4709' for '4709' from 10.13.22.63:5060 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Setting NAT on UDPTL to Off [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xa0aa1d0' [Aug 8 11:29:45] DEBUG[28074] res_rtp_asterisk.c: Allocated port 15518 for RTP instance '0xa0aa1d0' [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: RTP instance '0xa0aa1d0' is setup and ready to go [Aug 8 11:29:45] DEBUG[28074] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xa0aa1d0' [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Setting NAT on RTP to Off [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Setting NAT on UDPTL to Off [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing session-level SDP o=- 1167931180 1167931180 IN IP4 10.13.22.63... UNSUPPORTED. [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED. [Aug 8 11:29:45] DEBUG[28074] netsock2.c: Splitting '10.13.22.63' gives... [Aug 8 11:29:45] DEBUG[28074] netsock2.c: ...host '10.13.22.63' and port '(null)'. [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing session-level SDP c=IN IP4 10.13.22.63... OK. [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing session-level SDP a=sendrecv... OK. [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found RTP audio format 9 [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Setting payload 9 based on m type on 0xb7cf33cc [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found RTP audio format 0 [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Setting payload 0 based on m type on 0xb7cf33cc [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found RTP audio format 8 [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Setting payload 8 based on m type on 0xb7cf33cc [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found RTP audio format 18 [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Setting payload 18 based on m type on 0xb7cf33cc [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found RTP audio format 101 [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Setting payload 101 based on m type on 0xb7cf33cc [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found audio description format G722 for ID 9 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found audio description format PCMU for ID 0 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found audio description format G729 for ID 18 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED. [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Incorporating payload 0 on 0xb7cf33cc [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Incorporating payload 8 on 0xb7cf33cc [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Incorporating payload 9 on 0xb7cf33cc [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Incorporating payload 18 on 0xb7cf33cc [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Incorporating payload 101 on 0xb7cf33cc [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Capabilities: us - 0x100c (ulaw|alaw|g722), peer - audio=0x110c (ulaw|alaw|g729|g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x100c (ulaw|alaw|g722) [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Aug 8 11:29:45] DEBUG[28074] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xa0aa1d0' [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Peer audio RTP is at port 10.13.22.63:2246 [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Copying payload 0 from 0xb7cf33cc to 0xa0aa37c [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Copying payload 8 from 0xb7cf33cc to 0xa0aa37c [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Copying payload 9 from 0xb7cf33cc to 0xa0aa37c [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Copying payload 18 from 0xb7cf33cc to 0xa0aa37c [Aug 8 11:29:45] DEBUG[28074] rtp_engine.c: Copying payload 101 from 0xb7cf33cc to 0xa0aa37c [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Peer doesn't provide T.38 UDPTL [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: We're settling with these formats: 0x1000 (g722) [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Checking SIP call limits for device 4709 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Updating call counter for incoming call [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Call from peer '4709' is 1 out of 6 [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: Looking for 6000 in DLPN_DialPlanAll (domain 10.21.0.146:5061) [Aug 8 11:29:45] DEBUG[28074] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[28068] devicestate.c: No provider found, checking channel drivers for SIP - 4709 [Aug 8 11:29:45] DEBUG[28068] chan_sip.c: Checking device state for peer 4709 [Aug 8 11:29:45] DEBUG[28068] devicestate.c: Changing state for SIP/4709 - state 2 (In use) [Aug 8 11:29:45] DEBUG[28068] devicestate.c: device 'SIP/4709' state '2' [Aug 8 11:29:45] DEBUG[28074] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa0ec6a0 Query: SELECT * FROM extensions_table WHERE exten = '6000' AND context = 'ringgroups' AND priority = '1' [Aug 8 11:29:45] DEBUG[28074] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 8 11:29:45] DEBUG[28074] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[28074] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9fe9308 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '1' ORDER BY exten [Aug 8 11:29:45] DEBUG[28074] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: *** Our native formats are 0x1000 (g722) [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: *** Joint capabilities are 0x1000 (g722) [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: *** Our capabilities are 0x100c (ulaw|alaw|g722) [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x1000 (g722) [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: This channel will not be able to handle video. [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: build_route: Contact hop: [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: list_route: hop: [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Session timer started: 1575 - 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: SIP/4709-0000007c: New call is still down.... Trying... [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: <--- Transmitting (no NAT) to 10.13.22.63:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bKbc75a55bCE5C5AF0;received=10.13.22.63 From: "4709" ;tag=501CAE3D-AE03133A To: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 2 INVITE Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.13.22.63:5060 [Aug 8 11:29:45] DEBUG[28068] devicestate.c: No provider found, checking channel drivers for SIP - 4709 [Aug 8 11:29:45] DEBUG[28068] chan_sip.c: Checking device state for peer 4709 [Aug 8 11:29:45] DEBUG[28068] devicestate.c: Changing state for SIP/4709 - state 2 (In use) [Aug 8 11:29:45] DEBUG[28068] devicestate.c: device 'SIP/4709' state '2' [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9f54f60 Query: SELECT * FROM extensions_table WHERE exten = '6000' AND context = 'ringgroups' AND priority = '1' [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9f55000 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '1' ORDER BY exten [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9f55000 Query: SELECT * FROM extensions_table WHERE exten = '6000' AND context = 'ringgroups' AND priority = '1' [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9f55000 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '1' ORDER BY exten [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'EXTEN' is '6000' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [6000@DLPN_DialPlanAll:1] Set("SIP/4709-0000007c", "DN=6000") in new stack [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9f55000 Query: SELECT * FROM extensions_table WHERE exten = '6000' AND context = 'ringgroups' AND priority = '2' [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9f55000 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '2' ORDER BY exten [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is 'PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [6000@DLPN_DialPlanAll:2] Set("SIP/4709-0000007c", "UserAgent=PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439") in new stack [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9f55000 Query: SELECT * FROM extensions_table WHERE exten = '6000' AND context = 'ringgroups' AND priority = '3' [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9f55000 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '3' ORDER BY exten [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [6000@DLPN_DialPlanAll:3] Set("SIP/4709-0000007c", "CountReq=0") in new stack [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9ff3348 Query: SELECT * FROM extensions_table WHERE exten = '6000' AND context = 'ringgroups' AND priority = '4' [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9fce998 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '4' ORDER BY exten [Aug 8 11:29:45] DEBUG[21253] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Macro' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [6000@DLPN_DialPlanAll:4] Macro("SIP/4709-0000007c", "DialProcess") in new stack [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'CountReq' is '0' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Expression result is '1' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-DialProcess:1] Set("SIP/4709-0000007c", "CountReq=1") in new stack [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: Set [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'CountReq' is '1' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Expression result is '0' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'GotoIf' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-DialProcess:2] GotoIf("SIP/4709-0000007c", "0?1-End,1") in new stack [Aug 8 11:29:45] DEBUG[21253] pbx.c: Not taking any branch [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: GotoIf [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'WINIP' is '10.21.0.133:8090' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'DN' is '6000' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is '4709' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'PermissionExt' is NULL [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'Provider' is NULL [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is 'Polycom' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is 'Polycom' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'IsForward' is NULL [Aug 8 11:29:45] DEBUG[21253] func_curl.c: Called with data=0xb7b57ab8, str=0x9fc2838, realsize=50, len=16, used=0 [Aug 8 11:29:45] DEBUG[21253] func_curl.c: Now, len=64, used=50 [Aug 8 11:29:45] DEBUG[21253] func_curl.c: str='6000:6000::#4709#Polycom#internal#${DEFTIMEOUT}###' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is '6000:6000::#4709#Polycom#internal#${DEFTIMEOUT}###' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-DialProcess:3] Set("SIP/4709-0000007c", "RuleResult=6000:6000::#4709#Polycom#internal#${DEFTIMEOUT}###") in new stack [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: Set [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'DEF_LANG_PREFIX' is 'ru' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-DialProcess:4] Set("SIP/4709-0000007c", "CHANNEL(language)=ru") in new stack [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: Set [Aug 8 11:29:45] DEBUG[21253] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'RuleResult' is '6000:6000::#4709#Polycom#internal#${DEFTIMEOUT}###' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is 'internal' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-DialProcess:5] Set("SIP/4709-0000007c", "CommandType=internal") in new stack [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: Set [Aug 8 11:29:45] DEBUG[21253] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'RuleResult' is '6000:6000::#4709#Polycom#internal#${DEFTIMEOUT}###' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is '' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-DialProcess:6] Set("SIP/4709-0000007c", "Announc=") in new stack [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: Set [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'Announc' is '' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is '0' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Expression result is '1' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'GotoIf' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-DialProcess:7] GotoIf("SIP/4709-0000007c", "1?1-Switch,1") in new stack [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Goto (macro-DialProcess,1-Switch,1) [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: GotoIf [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'CommandType' is 'internal' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Expression result is '1' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'GotoIf' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [1-Switch@macro-DialProcess:1] GotoIf("SIP/4709-0000007c", "1?1-Internal,1") in new stack [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Goto (macro-DialProcess,1-Internal,1) [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: GotoIf [Aug 8 11:29:45] DEBUG[21253] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'RuleResult' is '6000:6000::#4709#Polycom#internal#${DEFTIMEOUT}###' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is '6000:6000::' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'RuleResult' is '6000:6000::#4709#Polycom#internal#${DEFTIMEOUT}###' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is '${DEFTIMEOUT}' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'DEFTIMEOUT' is '20' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is '20' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Macro' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [1-Internal@macro-DialProcess:1] Macro("SIP/4709-0000007c", "Dial-Local,6000:6000::,20") in new stack [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'NoOp' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-Dial-Local:1] NoOp("SIP/4709-0000007c", "Dial-Local") in new stack [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: Noop [Aug 8 11:29:45] DEBUG[21253] pbx.c: Evaluating 'ARG1' (from 'ARG1}' len 4) [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'ARG1' is '6000:6000::' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is '6000' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-Dial-Local:2] Set("SIP/4709-0000007c", "MyDN=6000") in new stack [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: Set [Aug 8 11:29:45] DEBUG[21253] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'RuleResult' is '6000:6000::#4709#Polycom#internal#${DEFTIMEOUT}###' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is '4709' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-Dial-Local:3] Set("SIP/4709-0000007c", "CALLERID(num)=4709") in new stack [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: Set [Aug 8 11:29:45] DEBUG[21253] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'RuleResult' is '6000:6000::#4709#Polycom#internal#${DEFTIMEOUT}###' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Function result is 'Polycom' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-Dial-Local:4] Set("SIP/4709-0000007c", "CALLERID(name)=Polycom") in new stack [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: Set [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'MyDN' is '6000' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Set' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-Dial-Local:5] Set("SIP/4709-0000007c", "__PICKUPMARK=6000") in new stack [Aug 8 11:29:45] DEBUG[21253] app_macro.c: Executed application: Set [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'MyDN' is '6000' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Result of 'ARG2' is '20' [Aug 8 11:29:45] DEBUG[21253] pbx.c: Launching 'Dial' [Aug 8 11:29:45] VERBOSE[21253] pbx.c: -- Executing [s@macro-Dial-Local:6] Dial("SIP/4709-0000007c", "SIP/6000,20") in new stack [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Asked to create a SIP channel with formats: 0x1000 (g722) [Aug 8 11:29:45] VERBOSE[21253] netsock.c: == Using UDPTL CoS mark 5 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Allocating new SIP dialog for 4937f86d394a2bc76bb06a1f156c04d9@127.0.0.1:0 - INVITE (No RTP) [Aug 8 11:29:45] DEBUG[21253] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9f42b70' [Aug 8 11:29:45] DEBUG[21253] res_rtp_asterisk.c: Allocated port 17434 for RTP instance '0x9f42b70' [Aug 8 11:29:45] DEBUG[21253] rtp_engine.c: RTP instance '0x9f42b70' is setup and ready to go [Aug 8 11:29:45] DEBUG[21253] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9f42b70' [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Setting NAT on RTP to Off [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Setting NAT on UDPTL to Off [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Aug 8 11:29:45] DEBUG[21253] acl.c: For destination '10.13.2.18', our source address is '10.21.0.146'. [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 10.21.0.146:5061 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: *** Our native formats are 0x8 (alaw) [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: *** Joint capabilities are 0x0 (nothing) [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: *** Our preferred formats from the incoming channel are 0x1000 (g722) [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: This channel will not be able to handle video. [Aug 8 11:29:45] DEBUG[21253] rtp_engine.c: Seeded SDP of 'SIP/6000-0000007d' with that of 'SIP/4709-0000007c' [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable DIALEDTIME. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable ANSWEREDTIME. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable DIALEDPEERNAME. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable DIALEDPEERNUMBER. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable DIALSTATUS. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable MACRO_DEPTH. [Aug 8 11:29:45] DEBUG[21253] channel.c: Copying hard-transferable variable PICKUPMARK. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable MyDN. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable ARG2. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable ARG1. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable MACRO_PRIORITY. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable MACRO_CONTEXT. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable MACRO_EXTEN. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable Announc. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable CommandType. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable RuleResult. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable CountReq. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable UserAgent. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable DN. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable SIPCALLID. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable SIPDOMAIN. [Aug 8 11:29:45] DEBUG[21253] channel.c: Not copying variable SIPURI. [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Outgoing Call for 6000 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Updating call counter for outgoing call [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Call to peer '6000' is 1 out of 6 [Aug 8 11:29:45] DEBUG[28068] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 8 11:29:45] DEBUG[28068] chan_sip.c: Checking device state for peer 6000 [Aug 8 11:29:45] DEBUG[28068] devicestate.c: Changing state for SIP/6000 - state 6 (Ringing) [Aug 8 11:29:45] DEBUG[28068] devicestate.c: device 'SIP/6000' state '6' [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: False Text flag: False [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: ** Our prefcodec: 0x1000 (g722) [Aug 8 11:29:45] VERBOSE[21253] chan_sip.c: Audio is at 5061 [Aug 8 11:29:45] VERBOSE[21253] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 8 11:29:45] VERBOSE[21253] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Aug 8 11:29:45] VERBOSE[21253] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: -- Done with adding codecs to SDP [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Initializing initreq for method INVITE - callid 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 0 [ 39]: INVITE sip:6000@10.13.2.18:5060 SIP/2.0 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK2403171b [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 3 [ 58]: From: "Polycom" ;tag=as3b544cd5 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 4 [ 30]: To: [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 5 [ 36]: Contact: [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 6 [ 58]: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.8.0-beta2 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 9 [ 35]: Date: Sun, 08 Aug 2010 08:29:45 GMT [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 10 [ 20]: Session-Expires: 200 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 12 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [Aug 8 11:29:45] VERBOSE[21253] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.2.18:5060: INVITE sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK2403171b Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Date: Sun, 08 Aug 2010 08:29:45 GMT Session-Expires: 200 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 287 v=0 o=root 186394824 186394824 IN IP4 10.21.0.146 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.21.0.146 t=0 0 m=audio 17434 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #1577 [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.13.2.18:5060 [Aug 8 11:29:45] VERBOSE[21253] app_dial.c: -- Called 6000 [Aug 8 11:29:45] DEBUG[21253] channel.c: Set channel SIP/6000-0000007d to read format slin [Aug 8 11:29:45] DEBUG[21253] channel.c: Set channel SIP/4709-0000007c to write format slin [Aug 8 11:29:45] DEBUG[21253] channel.c: Set channel SIP/4709-0000007c to read format slin [Aug 8 11:29:45] DEBUG[21253] channel.c: Set channel SIP/6000-0000007d to write format slin [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.2.18:5060 ---> SIP/2.0 180 Ringing From: "Polycom";tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK2403171b Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Allow: REGISTER, INVITE, ACK, BYE, REFER, NOTIFY, CANCEL, INFO, OPTIONS, PRACK, SUBSCRIBE Contact: Content-Length: 0 <-------------> [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 1 [ 57]: From: "Polycom";tag=as3b544cd5 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 2 [ 88]: To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 3 [ 58]: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 4 [ 16]: CSeq: 102 INVITE [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 5 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK2403171b [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 6 [ 26]: Supported: replaces,100rel [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 7 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 8 [ 89]: Allow: REGISTER, INVITE, ACK, BYE, REFER, NOTIFY, CANCEL, INFO, OPTIONS, PRACK, SUBSCRIBE [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 9 [ 35]: Contact: [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: Header 11 [ 0]: [Aug 8 11:29:45] VERBOSE[28074] chan_sip.c: --- (11 headers 0 lines) --- [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: *** SIP TIMER: Cancelling retransmission #1577 - INVITE (got response) [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Request 102: Found [Aug 8 11:29:45] DEBUG[28074] chan_sip.c: SIP response 180 to standard invite [Aug 8 11:29:45] VERBOSE[21253] app_dial.c: -- SIP/6000-0000007d is ringing [Aug 8 11:29:45] DEBUG[21253] rtp_engine.c: Setting early bridge SDP of 'SIP/4709-0000007c' with that of 'SIP/6000-0000007d' [Aug 8 11:29:45] VERBOSE[21253] chan_sip.c: <--- Transmitting (no NAT) to 10.13.22.63:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bKbc75a55bCE5C5AF0;received=10.13.22.63 From: "4709" ;tag=501CAE3D-AE03133A To: ;tag=as78046c0c Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 2 INVITE Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Aug 8 11:29:45] DEBUG[21253] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 10.13.22.63:5060 [Aug 8 11:29:45] DEBUG[28068] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 8 11:29:45] DEBUG[28068] chan_sip.c: Checking device state for peer 6000 [Aug 8 11:29:45] DEBUG[28068] devicestate.c: Changing state for SIP/6000 - state 6 (Ringing) [Aug 8 11:29:45] DEBUG[28068] devicestate.c: device 'SIP/6000' state '6' [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.2.18:5060 ---> SIP/2.0 200 OK From: "Polycom";tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 102 INVITE Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK2403171b Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Allow: REGISTER, INVITE, ACK, BYE, REFER, NOTIFY, CANCEL, INFO, OPTIONS, PRACK, SUBSCRIBE Contact: Content-Type: application/sdp Content-Length: 198 v=0 o=6000 947634313 947634313 IN IP4 10.13.2.18 s=- c=IN IP4 10.13.2.18 t=0 0 m=audio 4000 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 1 [ 57]: From: "Polycom";tag=as3b544cd5 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 2 [ 88]: To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 3 [ 58]: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 4 [ 16]: CSeq: 102 INVITE [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 5 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK2403171b [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 6 [ 26]: Supported: replaces,100rel [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 7 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 8 [ 89]: Allow: REGISTER, INVITE, ACK, BYE, REFER, NOTIFY, CANCEL, INFO, OPTIONS, PRACK, SUBSCRIBE [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 9 [ 35]: Contact: [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 11 [ 19]: Content-Length: 198 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 12 [ 0]: [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 0 [ 3]: v=0 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 1 [ 44]: o=6000 947634313 947634313 IN IP4 10.13.2.18 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 2 [ 3]: s=- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 3 [ 19]: c=IN IP4 10.13.2.18 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 5 [ 26]: m=audio 4000 RTP/AVP 8 101 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 7 [ 10]: a=ptime:20 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 9 [ 15]: a=fmtp:101 0-15 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: --- (12 headers 10 lines) --- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Acked pending invite 102 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Stopping retransmission on '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' of Request 102: Match Found [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: SIP response 200 to standard invite [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP o=6000 947634313 947634313 IN IP4 10.13.2.18... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP s=-... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.2.18' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.2.18' and port '(null)'. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP c=IN IP4 10.13.2.18... OK. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found RTP audio format 8 [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Setting payload 8 based on m type on 0xb7cf351c [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found RTP audio format 101 [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Setting payload 101 based on m type on 0xb7cf351c [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Incorporating payload 8 on 0xb7cf351c [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Incorporating payload 101 on 0xb7cf351c [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw) [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Aug 8 11:29:47] DEBUG[28074] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9f42b70' [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Peer audio RTP is at port 10.13.2.18:4000 [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Copying payload 8 from 0xb7cf351c to 0x9f42d1c [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Copying payload 101 from 0xb7cf351c to 0x9f42d1c [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Peer doesn't provide T.38 UDPTL [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: We have an owner, now see if we need to change this call [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Updating call counter for outgoing call [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: build_route: Contact hop: [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: list_route: hop: [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.2.18:5060' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.2.18' and port '5060'. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Session timer started: 1580 - 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Strict routing enforced for session 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.2.18:5060' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.2.18' and port '5060'. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.2.18:5060 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Transmitting (no NAT) to 10.13.2.18:5060: ACK sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK72397b77 Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 102 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Trying to put 'ACK sip:600' onto UDP socket destined for 10.13.2.18:5060 [Aug 8 11:29:47] VERBOSE[21253] app_dial.c: -- SIP/6000-0000007d answered SIP/4709-0000007c [Aug 8 11:29:47] DEBUG[21253] rtp_engine.c: Setting early bridge SDP of 'SIP/4709-0000007c' with that of 'SIP/6000-0000007d' [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: SIP answering channel: SIP/4709-0000007c [Aug 8 11:29:47] DEBUG[21253] res_rtp_asterisk.c: Setting the marker bit due to a source update [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Setting framing from config on incoming call [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: ** Our capability: 0x1000 (g722) Video flag: True Text flag: True [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: Audio is at 5061 [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: Adding codec 0x1000 (g722) to SDP [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: -- Done with adding codecs to SDP [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Done building SDP. Settling with this capability: 0x1000 (g722) [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: <--- Reliably Transmitting (no NAT) to 10.13.22.63:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bKbc75a55bCE5C5AF0;received=10.13.22.63 From: "4709" ;tag=501CAE3D-AE03133A To: ;tag=as78046c0c Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 2 INVITE Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 265 v=0 o=root 1473530712 1473530712 IN IP4 10.21.0.146 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.21.0.146 t=0 0 m=audio 15518 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #1581 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.13.22.63:5060 [Aug 8 11:29:47] DEBUG[21253] features.c: bridge answer set, chan answer set [Aug 8 11:29:47] DEBUG[21253] res_rtp_asterisk.c: Setting the marker bit due to a source update [Aug 8 11:29:47] DEBUG[21253] res_rtp_asterisk.c: Setting the marker bit due to a source update [Aug 8 11:29:47] VERBOSE[21253] rtp_engine.c: -- Remotely bridging SIP/4709-0000007c and SIP/6000-0000007d [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Deferring reinvite on SIP '4bfd8dbe-e22855af-63414b54@10.13.22.63' - It's audio will be redirected to IP 10.13.2.18:4000 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Sending reinvite on SIP '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' - It's audio soon redirected to IP 10.13.22.63:2246 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Strict routing enforced for session 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:29:47] DEBUG[21253] netsock2.c: Splitting '10.13.2.18:5060' gives... [Aug 8 11:29:47] DEBUG[21253] netsock2.c: ...host '10.13.2.18' and port '5060'. [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: set_destination: set destination to 10.13.2.18:5060 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: ** Our capability: 0x8 (alaw) Video flag: True Text flag: True [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: ** Our prefcodec: 0x1000 (g722) [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: Audio is at 5061 [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: -- Done with adding codecs to SDP [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Done building SDP. Settling with this capability: 0x8 (alaw) [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Initializing already initialized SIP dialog 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 (presumably reinvite) [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 0 [ 39]: INVITE sip:6000@10.13.2.18:5060 SIP/2.0 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK75ee739f [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 3 [ 58]: From: "Polycom" ;tag=as3b544cd5 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 4 [ 88]: To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 5 [ 36]: Contact: [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 6 [ 58]: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 7 [ 16]: CSeq: 103 INVITE [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.8.0-beta2 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 10 [ 26]: Supported: replaces, timer [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.2.18:5060: INVITE sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK75ee739f Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 103 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 262 v=0 o=root 186394824 186394825 IN IP4 10.13.22.63 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.13.22.63 t=0 0 m=audio 2246 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #1582 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.13.2.18:5060 [Aug 8 11:29:47] DEBUG[28068] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 8 11:29:47] DEBUG[28068] chan_sip.c: Checking device state for peer 6000 [Aug 8 11:29:47] DEBUG[28068] devicestate.c: Changing state for SIP/6000 - state 3 (Busy) [Aug 8 11:29:47] DEBUG[28068] devicestate.c: device 'SIP/6000' state '3' [Aug 8 11:29:47] DEBUG[28068] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 8 11:29:47] DEBUG[28068] chan_sip.c: Checking device state for peer 6000 [Aug 8 11:29:47] DEBUG[28068] devicestate.c: Changing state for SIP/6000 - state 3 (Busy) [Aug 8 11:29:47] DEBUG[28068] devicestate.c: device 'SIP/6000' state '3' [Aug 8 11:29:47] DEBUG[28068] devicestate.c: No provider found, checking channel drivers for SIP - 4709 [Aug 8 11:29:47] DEBUG[28068] chan_sip.c: Checking device state for peer 4709 [Aug 8 11:29:47] DEBUG[28068] devicestate.c: Changing state for SIP/4709 - state 2 (In use) [Aug 8 11:29:47] DEBUG[28068] devicestate.c: device 'SIP/4709' state '2' [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: INVITE [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.22.63:5060 ---> ACK sip:6000@10.21.0.146:5061 SIP/2.0 Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bK25186147675F03CC From: "4709" ;tag=501CAE3D-AE03133A To: ;tag=as78046c0c CSeq: 2 ACK Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 Accept-Language: en Max-Forwards: 70 Content-Length: 0 <-------------> [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 0 [ 37]: ACK sip:6000@10.21.0.146:5061 SIP/2.0 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 10.13.22.63;branch=z9hG4bK25186147675F03CC [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 2 [ 57]: From: "4709" ;tag=501CAE3D-AE03133A [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 3 [ 52]: To: ;tag=as78046c0c [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 4 [ 11]: CSeq: 2 ACK [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 5 [ 47]: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 6 [ 31]: Contact: [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 7 [ 96]: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 8 [ 54]: User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 9 [ 19]: Accept-Language: en [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 10 [ 16]: Max-Forwards: 70 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 12 [ 0]: [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: --- (12 headers 0 lines) --- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1581 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Stopping retransmission on '4bfd8dbe-e22855af-63414b54@10.13.22.63' of Response 2: Match Found [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Sending pending reinvite on '4bfd8dbe-e22855af-63414b54@10.13.22.63' [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Strict routing enforced for session 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.22.63' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.22.63' and port '(null)'. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.22.63:5060 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: ** Our capability: 0x1000 (g722) Video flag: True Text flag: True [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Audio is at 5061 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Adding codec 0x1000 (g722) to SDP [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: -- Done with adding codecs to SDP [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Done building SDP. Settling with this capability: 0x1000 (g722) [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Initializing already initialized SIP dialog 4bfd8dbe-e22855af-63414b54@10.13.22.63 (presumably reinvite) [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 0 [ 35]: INVITE sip:4709@10.13.22.63 SIP/2.0 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK48b0bed3 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 3 [ 54]: From: ;tag=as78046c0c [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 4 [ 55]: To: "4709" ;tag=501CAE3D-AE03133A [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 5 [ 36]: Contact: [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 6 [ 47]: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.8.0-beta2 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 10 [ 26]: Supported: replaces, timer [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.22.63:5060: INVITE sip:4709@10.13.22.63 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK48b0bed3 Max-Forwards: 70 From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A Contact: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 262 v=0 o=root 1473530712 1473530713 IN IP4 10.13.2.18 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.13.2.18 t=0 0 m=audio 4000 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #1583 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.13.22.63:5060 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.2.18:5060 ---> SIP/2.0 200 OK From: "Polycom";tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 103 INVITE Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK75ee739f Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Contact: Content-Type: application/sdp Content-Length: 198 v=0 o=6000 947634196 947634196 IN IP4 10.13.2.18 s=- c=IN IP4 10.13.2.18 t=0 0 m=audio 4000 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 1 [ 57]: From: "Polycom";tag=as3b544cd5 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 2 [ 88]: To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 3 [ 58]: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 4 [ 16]: CSeq: 103 INVITE [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 5 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK75ee739f [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 6 [ 26]: Supported: replaces,100rel [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 7 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 8 [ 35]: Contact: [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 10 [ 19]: Content-Length: 198 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 11 [ 0]: [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 0 [ 3]: v=0 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 1 [ 44]: o=6000 947634196 947634196 IN IP4 10.13.2.18 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 2 [ 3]: s=- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 3 [ 19]: c=IN IP4 10.13.2.18 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 5 [ 26]: m=audio 4000 RTP/AVP 8 101 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 7 [ 10]: a=ptime:20 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 9 [ 15]: a=fmtp:101 0-15 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: --- (11 headers 10 lines) --- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Acked pending invite 103 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1582 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Stopping retransmission on '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' of Request 103: Match Found [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: SIP response 200 to RE-invite on outgoing call 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Call 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 responded to our reinvite without changing SDP version; ignoring SDP. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Updating call counter for outgoing call [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.2.18:5060' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.2.18' and port '5060'. [Aug 8 11:29:47] DEBUG[28068] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 8 11:29:47] DEBUG[28068] chan_sip.c: Checking device state for peer 6000 [Aug 8 11:29:47] DEBUG[28068] devicestate.c: Changing state for SIP/6000 - state 3 (Busy) [Aug 8 11:29:47] DEBUG[28068] devicestate.c: device 'SIP/6000' state '3' [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Strict routing enforced for session 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.2.18:5060' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.2.18' and port '5060'. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.2.18:5060 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Transmitting (no NAT) to 10.13.2.18:5060: ACK sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK5fc18d62 Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 103 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Trying to put 'ACK sip:600' onto UDP socket destined for 10.13.2.18:5060 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.22.63:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK48b0bed3 From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A CSeq: 102 INVITE Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 Accept-Language: en Content-Type: application/sdp Content-Length: 197 v=0 o=- 1167931180 1167931181 IN IP4 10.13.22.63 s=Polycom IP Phone c=IN IP4 10.13.22.63 t=0 0 m=audio 2246 RTP/AVP 9 101 a=sendrecv a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 <-------------> [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK48b0bed3 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 2 [ 54]: From: ;tag=as78046c0c [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 3 [ 55]: To: "4709" ;tag=501CAE3D-AE03133A [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 4 [ 16]: CSeq: 102 INVITE [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 5 [ 47]: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 6 [ 31]: Contact: [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 7 [ 96]: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 8 [ 54]: User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 9 [ 19]: Accept-Language: en [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 11 [ 19]: Content-Length: 197 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 12 [ 0]: [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 0 [ 3]: v=0 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 1 [ 44]: o=- 1167931180 1167931181 IN IP4 10.13.22.63 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 2 [ 18]: s=Polycom IP Phone [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.13.22.63 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 5 [ 26]: m=audio 2246 RTP/AVP 9 101 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 6 [ 10]: a=sendrecv [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 7 [ 20]: a=rtpmap:9 G722/8000 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: --- (12 headers 9 lines) --- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Acked pending invite 102 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1583 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Stopping retransmission on '4bfd8dbe-e22855af-63414b54@10.13.22.63' of Request 102: Match Found [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: SIP response 200 to RE-invite on outgoing call 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP o=- 1167931180 1167931181 IN IP4 10.13.22.63... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP s=Polycom IP Phone... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.22.63' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.22.63' and port '(null)'. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP c=IN IP4 10.13.22.63... OK. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found RTP audio format 9 [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Setting payload 9 based on m type on 0xb7cf351c [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found RTP audio format 101 [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Setting payload 101 based on m type on 0xb7cf351c [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found audio description format G722 for ID 9 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Incorporating payload 9 on 0xb7cf351c [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Incorporating payload 101 on 0xb7cf351c [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Capabilities: us - 0x100c (ulaw|alaw|g722), peer - audio=0x1000 (g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x1000 (g722) [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Aug 8 11:29:47] DEBUG[28074] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xa0aa1d0' [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Peer audio RTP is at port 10.13.22.63:2246 [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Copying payload 9 from 0xb7cf351c to 0xa0aa37c [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Copying payload 101 from 0xb7cf351c to 0xa0aa37c [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Peer doesn't provide T.38 UDPTL [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: We're settling with these formats: 0x1000 (g722) [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: We have an owner, now see if we need to change this call [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Updating call counter for incoming call [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.22.63' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.22.63' and port '(null)'. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Strict routing enforced for session 4bfd8dbe-e22855af-63414b54@10.13.22.63 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.22.63' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.22.63' and port '(null)'. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.22.63:5060 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Transmitting (no NAT) to 10.13.22.63:5060: ACK sip:4709@10.13.22.63 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK558957f6 Max-Forwards: 70 From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A Contact: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 102 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Trying to put 'ACK sip:470' onto UDP socket destined for 10.13.22.63:5060 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:47] DEBUG[21253] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw [Aug 8 11:29:47] DEBUG[21253] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160 [Aug 8 11:29:47] DEBUG[21253] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x9f42b70' [Aug 8 11:29:47] DEBUG[21253] rtp_engine.c: Oooh, 'SIP/4709-0000007c' changed end address to 10.13.22.63:2246 (format g722) [Aug 8 11:29:47] DEBUG[21253] rtp_engine.c: Oooh, 'SIP/4709-0000007c' was 10.13.22.63:2246/(format unknown) [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Sending reinvite on SIP '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' - It's audio soon redirected to IP 10.13.22.63:2246 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Strict routing enforced for session 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:29:47] DEBUG[21253] netsock2.c: Splitting '10.13.2.18:5060' gives... [Aug 8 11:29:47] DEBUG[21253] netsock2.c: ...host '10.13.2.18' and port '5060'. [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: set_destination: set destination to 10.13.2.18:5060 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: ** Our capability: 0x8 (alaw) Video flag: True Text flag: True [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: ** Our prefcodec: 0x1000 (g722) [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: Audio is at 5061 [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: -- Done with adding codecs to SDP [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Done building SDP. Settling with this capability: 0x8 (alaw) [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Initializing already initialized SIP dialog 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 (presumably reinvite) [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 0 [ 39]: INVITE sip:6000@10.13.2.18:5060 SIP/2.0 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK6f8f48ca [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 3 [ 58]: From: "Polycom" ;tag=as3b544cd5 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 4 [ 88]: To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 5 [ 36]: Contact: [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 6 [ 58]: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 7 [ 16]: CSeq: 104 INVITE [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.8.0-beta2 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 10 [ 26]: Supported: replaces, timer [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Aug 8 11:29:47] VERBOSE[21253] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.2.18:5060: INVITE sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK6f8f48ca Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 104 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 262 v=0 o=root 186394824 186394826 IN IP4 10.13.22.63 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.13.22.63 t=0 0 m=audio 2246 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #1586 [Aug 8 11:29:47] DEBUG[21253] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.13.2.18:5060 [Aug 8 11:29:47] DEBUG[28068] devicestate.c: No provider found, checking channel drivers for SIP - 4709 [Aug 8 11:29:47] DEBUG[28068] chan_sip.c: Checking device state for peer 4709 [Aug 8 11:29:47] DEBUG[28068] devicestate.c: Changing state for SIP/4709 - state 2 (In use) [Aug 8 11:29:47] DEBUG[28068] devicestate.c: device 'SIP/4709' state '2' [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.2.18:5060 ---> SIP/2.0 200 OK From: "Polycom";tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 104 INVITE Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK6f8f48ca Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Contact: Content-Type: application/sdp Content-Length: 198 v=0 o=6000 947634327 947634327 IN IP4 10.13.2.18 s=- c=IN IP4 10.13.2.18 t=0 0 m=audio 4000 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 1 [ 57]: From: "Polycom";tag=as3b544cd5 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 2 [ 88]: To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 3 [ 58]: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 4 [ 16]: CSeq: 104 INVITE [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 5 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK6f8f48ca [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 6 [ 26]: Supported: replaces,100rel [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 7 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 8 [ 35]: Contact: [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 10 [ 19]: Content-Length: 198 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Header 11 [ 0]: [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 0 [ 3]: v=0 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 1 [ 44]: o=6000 947634327 947634327 IN IP4 10.13.2.18 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 2 [ 3]: s=- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 3 [ 19]: c=IN IP4 10.13.2.18 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 5 [ 26]: m=audio 4000 RTP/AVP 8 101 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 7 [ 10]: a=ptime:20 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Body 9 [ 15]: a=fmtp:101 0-15 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: --- (11 headers 10 lines) --- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Acked pending invite 104 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1586 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Stopping retransmission on '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' of Request 104: Match Found [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: SIP response 200 to RE-invite on outgoing call 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP o=6000 947634327 947634327 IN IP4 10.13.2.18... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP s=-... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.2.18' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.2.18' and port '(null)'. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP c=IN IP4 10.13.2.18... OK. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found RTP audio format 8 [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Setting payload 8 based on m type on 0xb7cf351c [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found RTP audio format 101 [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Setting payload 101 based on m type on 0xb7cf351c [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Incorporating payload 8 on 0xb7cf351c [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Incorporating payload 101 on 0xb7cf351c [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw) [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Aug 8 11:29:47] DEBUG[28074] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9f42b70' [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Peer audio RTP is at port 10.13.2.18:4000 [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Copying payload 8 from 0xb7cf351c to 0x9f42d1c [Aug 8 11:29:47] DEBUG[28074] rtp_engine.c: Copying payload 101 from 0xb7cf351c to 0x9f42d1c [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Peer doesn't provide T.38 UDPTL [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: We have an owner, now see if we need to change this call [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Updating call counter for outgoing call [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.2.18:5060' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.2.18' and port '5060'. [Aug 8 11:29:47] DEBUG[28068] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 8 11:29:47] DEBUG[28068] chan_sip.c: Checking device state for peer 6000 [Aug 8 11:29:47] DEBUG[28068] devicestate.c: Changing state for SIP/6000 - state 3 (Busy) [Aug 8 11:29:47] DEBUG[28068] devicestate.c: device 'SIP/6000' state '3' [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Strict routing enforced for session 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:29:47] DEBUG[28074] netsock2.c: Splitting '10.13.2.18:5060' gives... [Aug 8 11:29:47] DEBUG[28074] netsock2.c: ...host '10.13.2.18' and port '5060'. [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.2.18:5060 [Aug 8 11:29:47] VERBOSE[28074] chan_sip.c: Transmitting (no NAT) to 10.13.2.18:5060: ACK sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK6edaabcf Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 104 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Trying to put 'ACK sip:600' onto UDP socket destined for 10.13.2.18:5060 [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:47] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:48] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:48] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:49] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:49] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:50] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:50] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:51] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:51] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:52] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:52] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:52] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:52] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:53] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:53] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:54] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:54] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:55] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:55] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:56] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:56] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:57] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:57] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:57] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:57] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:57] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:57] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:58] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:58] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:29:59] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:29:59] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:30:00] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:30:00] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:30:01] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:30:01] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:30:02] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:30:02] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:30:02] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4bfd8dbe-e22855af-63414b54@10.13.22.63' Method: ACK [Aug 8 11:30:02] DEBUG[28074] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061' Method: INVITE [Aug 8 11:31:25] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:31:25] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.22.63:5060 [Aug 8 11:31:25] VERBOSE[28074] chan_sip.c: Audio is at 5061 [Aug 8 11:31:25] VERBOSE[28074] chan_sip.c: Adding codec 0x1000 (g722) to SDP [Aug 8 11:31:25] VERBOSE[28074] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 8 11:31:25] VERBOSE[28074] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.22.63:5060: INVITE sip:4709@10.13.22.63 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK3036df2d Max-Forwards: 70 From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A Contact: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 103 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (Session-Timers) Content-Type: application/sdp Content-Length: 262 v=0 o=root 1473530712 1473530713 IN IP4 10.13.2.18 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.13.2.18 t=0 0 m=audio 4000 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 8 11:31:25] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.22.63:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK3036df2d From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A CSeq: 103 INVITE Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 Accept-Language: en Content-Type: application/sdp Content-Length: 197 v=0 o=- 1167931180 1167931181 IN IP4 10.13.22.63 s=Polycom IP Phone c=IN IP4 10.13.22.63 t=0 0 m=audio 2246 RTP/AVP 9 101 a=sendrecv a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 <-------------> [Aug 8 11:31:25] VERBOSE[28074] chan_sip.c: --- (12 headers 9 lines) --- [Aug 8 11:31:25] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:31:25] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.22.63:5060 [Aug 8 11:31:25] VERBOSE[28074] chan_sip.c: Transmitting (no NAT) to 10.13.22.63:5060: ACK sip:4709@10.13.22.63 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK4cecd9ae Max-Forwards: 70 From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A Contact: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 103 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 8 11:31:27] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:31:27] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.2.18:5060 [Aug 8 11:31:27] VERBOSE[28074] chan_sip.c: Audio is at 5061 [Aug 8 11:31:27] VERBOSE[28074] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 8 11:31:27] VERBOSE[28074] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 8 11:31:27] VERBOSE[28074] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.2.18:5060: INVITE sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK23d14cd6 Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 105 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (Session-Timers) Content-Type: application/sdp Content-Length: 262 v=0 o=root 186394824 186394826 IN IP4 10.13.22.63 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.13.22.63 t=0 0 m=audio 2246 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 8 11:31:27] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.2.18:5060 ---> SIP/2.0 200 OK From: "Polycom";tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 105 INVITE Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK23d14cd6 Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Contact: Content-Type: application/sdp Content-Length: 198 v=0 o=6000 947634252 947634252 IN IP4 10.13.2.18 s=- c=IN IP4 10.13.2.18 t=0 0 m=audio 4000 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Aug 8 11:31:27] VERBOSE[28074] chan_sip.c: --- (11 headers 10 lines) --- [Aug 8 11:31:27] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:31:27] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.2.18:5060 [Aug 8 11:31:27] VERBOSE[28074] chan_sip.c: Transmitting (no NAT) to 10.13.2.18:5060: ACK sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK129aaa4c Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 105 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 8 11:33:05] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:33:05] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.22.63:5060 [Aug 8 11:33:05] VERBOSE[28074] chan_sip.c: Audio is at 5061 [Aug 8 11:33:05] VERBOSE[28074] chan_sip.c: Adding codec 0x1000 (g722) to SDP [Aug 8 11:33:05] VERBOSE[28074] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 8 11:33:05] VERBOSE[28074] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.22.63:5060: INVITE sip:4709@10.13.22.63 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK6ac4a2ba Max-Forwards: 70 From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A Contact: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 104 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (Session-Timers) Content-Type: application/sdp Content-Length: 262 v=0 o=root 1473530712 1473530713 IN IP4 10.13.2.18 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.13.2.18 t=0 0 m=audio 4000 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 8 11:33:05] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.22.63:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK6ac4a2ba From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A CSeq: 104 INVITE Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 Accept-Language: en Content-Type: application/sdp Content-Length: 197 v=0 o=- 1167931180 1167931181 IN IP4 10.13.22.63 s=Polycom IP Phone c=IN IP4 10.13.22.63 t=0 0 m=audio 2246 RTP/AVP 9 101 a=sendrecv a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 <-------------> [Aug 8 11:33:05] VERBOSE[28074] chan_sip.c: --- (12 headers 9 lines) --- [Aug 8 11:33:05] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:33:05] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.22.63:5060 [Aug 8 11:33:05] VERBOSE[28074] chan_sip.c: Transmitting (no NAT) to 10.13.22.63:5060: ACK sip:4709@10.13.22.63 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK7ceed40d Max-Forwards: 70 From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A Contact: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 104 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.2.18:5060 [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Audio is at 5061 [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.2.18:5060: INVITE sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK77a2ad1f Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 106 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (Session-Timers) Content-Type: application/sdp Content-Length: 262 v=0 o=root 186394824 186394826 IN IP4 10.13.22.63 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.13.22.63 t=0 0 m=audio 2246 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.2.18:5060 ---> SIP/2.0 200 OK From: "Polycom";tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 106 INVITE Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK77a2ad1f Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Contact: Content-Type: application/sdp Content-Length: 198 v=0 o=6000 947634339 947634339 IN IP4 10.13.2.18 s=- c=IN IP4 10.13.2.18 t=0 0 m=audio 4000 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: --- (11 headers 10 lines) --- [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Found RTP audio format 8 [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Found RTP audio format 101 [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw) [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Peer audio RTP is at port 10.13.2.18:4000 [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.2.18:5060 [Aug 8 11:33:07] VERBOSE[28074] chan_sip.c: Transmitting (no NAT) to 10.13.2.18:5060: ACK sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK796029d4 Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 106 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 8 11:34:45] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:34:45] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.22.63:5060 [Aug 8 11:34:45] VERBOSE[28074] chan_sip.c: Audio is at 5061 [Aug 8 11:34:45] VERBOSE[28074] chan_sip.c: Adding codec 0x1000 (g722) to SDP [Aug 8 11:34:45] VERBOSE[28074] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 8 11:34:45] VERBOSE[28074] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.22.63:5060: INVITE sip:4709@10.13.22.63 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK32c19eec Max-Forwards: 70 From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A Contact: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 105 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (Session-Timers) Content-Type: application/sdp Content-Length: 262 v=0 o=root 1473530712 1473530713 IN IP4 10.13.2.18 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.13.2.18 t=0 0 m=audio 4000 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 8 11:34:45] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.22.63:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK32c19eec From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A CSeq: 105 INVITE Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 Contact: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER User-Agent: PolycomSoundPointIP-SPIP_450-UA/3.1.3.0439 Accept-Language: en Content-Type: application/sdp Content-Length: 197 v=0 o=- 1167931180 1167931181 IN IP4 10.13.22.63 s=Polycom IP Phone c=IN IP4 10.13.22.63 t=0 0 m=audio 2246 RTP/AVP 9 101 a=sendrecv a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 <-------------> [Aug 8 11:34:45] VERBOSE[28074] chan_sip.c: --- (12 headers 9 lines) --- [Aug 8 11:34:45] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:34:45] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.22.63:5060 [Aug 8 11:34:45] VERBOSE[28074] chan_sip.c: Transmitting (no NAT) to 10.13.22.63:5060: ACK sip:4709@10.13.22.63 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK1723f0e9 Max-Forwards: 70 From: ;tag=as78046c0c To: "4709" ;tag=501CAE3D-AE03133A Contact: Call-ID: 4bfd8dbe-e22855af-63414b54@10.13.22.63 CSeq: 105 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.2.18:5060 [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Audio is at 5061 [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.2.18:5060: INVITE sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK21b45f67 Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 107 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (Session-Timers) Content-Type: application/sdp Content-Length: 262 v=0 o=root 186394824 186394826 IN IP4 10.13.22.63 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.13.22.63 t=0 0 m=audio 2246 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: <--- SIP read from UDP:10.13.2.18:5060 ---> SIP/2.0 200 OK From: "Polycom";tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 107 INVITE Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK21b45f67 Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Contact: Content-Type: application/sdp Content-Length: 198 v=0 o=6000 947634429 947634429 IN IP4 10.13.2.18 s=- c=IN IP4 10.13.2.18 t=0 0 m=audio 4000 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: --- (11 headers 10 lines) --- [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Found RTP audio format 8 [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Found RTP audio format 101 [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw) [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Peer audio RTP is at port 10.13.2.18:4000 [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: set_destination: set destination to 10.13.2.18:5060 [Aug 8 11:34:47] VERBOSE[28074] chan_sip.c: Transmitting (no NAT) to 10.13.2.18:5060: ACK sip:6000@10.13.2.18:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK72741419 Max-Forwards: 70 From: "Polycom" ;tag=as3b544cd5 To: ;tag=87a110-12020d0a-13c4-50029-387bbe65-4fc41509-387bbe65 Contact: Call-ID: 4d11429f22eb328e2586afb9418d6b8f@10.21.0.146:5061 CSeq: 107 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 ---