[May 27 17:34:43] DEBUG[28657]: chan_sip.c:4412 __sip_autodestruct: Auto destroying SIP dialog '845462758' [May 27 17:34:43] DEBUG[28657]: chan_sip.c:6817 sip_destroy: Destroying SIP dialog 845462758 Really destroying SIP dialog '845462758' Method: REGISTER <--- SIP read from UDP:78.26.144.10:5060 ---> INVITE sip:6000333@209.239.114.51 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK1028478031 From: ;tag=1085286111 To: "Doctor" Call-ID: 1783459290 CSeq: 20 INVITE Contact: Content-Type: application/sdp Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Max-Forwards: 70 User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Subject: Phone call Content-Length: 229 v=0 o=6000444 171 2041 IN IP4 78.26.144.10 s=Talk c=IN IP4 78.26.144.10 b=AS:380 t=0 0 m=audio 7076 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 a=rtcp:7077 IN IP4 192.168.1.107 <-------------> [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 41]: INVITE sip:6000333@209.239.114.51 SIP/2.0 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK1028478031 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 56]: From: ;tag=1085286111 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 41]: To: "Doctor" [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1783459290 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 15]: CSeq: 20 INVITE [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 44]: Contact: [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 29]: Content-Type: application/sdp [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 16]: Max-Forwards: 70 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 11 [ 19]: Subject: Phone call [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 12 [ 19]: Content-Length: 229 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 13 [ 0]: [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 0 [ 3]: v=0 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 1 [ 38]: o=6000444 171 2041 IN IP4 78.26.144.10 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 2 [ 6]: s=Talk [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 3 [ 21]: c=IN IP4 78.26.144.10 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 4 [ 8]: b=AS:380 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 5 [ 5]: t=0 0 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 6 [ 26]: m=audio 7076 RTP/AVP 9 101 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 7 [ 20]: a=rtpmap:9 G722/8000 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 9 [ 15]: a=fmtp:101 0-11 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9605 parse_request: Body 10 [ 32]: a=rtcp:7077 IN IP4 192.168.1.107 --- (13 headers 11 lines) --- [May 27 17:34:47] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1783459290 (Checking From) --From tag 1085286111 --To-tag [May 27 17:34:47] DEBUG[28657]: logger.c:1294 ast_create_callid: CALL_ID [C-00000199] created by thread. [May 27 17:34:47] DEBUG[28657]: acl.c:979 ast_ouraddrfor: For destination '78.26.144.10', our source address is '209.239.114.51'. [May 27 17:34:47] DEBUG[28657]: chan_sip.c:4021 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 209.239.114.51:5060 [May 27 17:34:47] DEBUG[28657]: chan_sip.c:8721 sip_alloc: Allocating new SIP dialog for 1783459290 - INVITE (No RTP) [May 27 17:34:47] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:47] DEBUG[28657][C-00000199]: chan_sip.c:27866 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE [May 27 17:34:47] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.1.107:5060' into... [May 27 17:34:47] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.1.107' and port '5060'. [May 27 17:34:47] DEBUG[28657][C-00000199]: chan_sip.c:17845 check_via: NAT detected for 192.168.1.107:5060 / 78.26.144.10:5060 Sending to 78.26.144.10:5060 (NAT) [May 27 17:34:47] DEBUG[28657][C-00000199]: chan_sip.c:24999 handle_request_invite: Initializing initreq for method INVITE - callid 1783459290 Using INVITE request as basis request - 1783459290 [May 27 17:34:47] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:40412' into... [May 27 17:34:47] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port ''. Found peer '6000444' for '6000444' from 78.26.144.10:5060 <--- Reliably Transmitting (NAT) to 78.26.144.10:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.107:5060;branch=z9hG4bK1028478031;received=78.26.144.10;rport=5060 From: ;tag=1085286111 To: "Doctor" ;tag=as2361a4da Call-ID: 1783459290 CSeq: 20 INVITE Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="vm.intersog.com", nonce="0d7f2bf7" Content-Length: 0 <------------> [May 27 17:34:47] DEBUG[28657][C-00000199]: chan_sip.c:4324 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #432280 [May 27 17:34:47] DEBUG[28657][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 78.26.144.10:5060 Scheduling destruction of SIP dialog '1783459290' in 32000 ms (Method: INVITE) [May 27 17:34:47] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:78.26.144.10:5060 ---> ACK sip:6000333@209.239.114.51 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK1028478031 From: ;tag=1085286111 To: "Doctor" ;tag=as2361a4da Call-ID: 1783459290 CSeq: 20 ACK Content-Length: 0 <-------------> [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 38]: ACK sip:6000333@209.239.114.51 SIP/2.0 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK1028478031 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 56]: From: ;tag=1085286111 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 56]: To: "Doctor" ;tag=as2361a4da [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1783459290 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 12]: CSeq: 20 ACK [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 17]: Content-Length: 0 --- (7 headers 0 lines) --- [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1783459290 (Checking From) --From tag 1085286111 --To-tag as2361a4da [May 27 17:34:48] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:27866 handle_incoming: **** Received ACK (6) - Command in SIP ACK [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:4523 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #432280 [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:4556 __sip_ack: Stopping retransmission on '1783459290' of Response 20: Match Found [May 27 17:34:48] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:78.26.144.10:5060 ---> INVITE sip:6000333@209.239.114.51 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK2087609245 From: ;tag=1085286111 To: "Doctor" Call-ID: 1783459290 CSeq: 21 INVITE Contact: Authorization: Digest username="6000444", realm="vm.intersog.com", nonce="0d7f2bf7", uri="sip:6000333@209.239.114.51", response="6eb0c6f26c97d4159f37bb0aa0add4b7", algorithm=MD5 Content-Type: application/sdp Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Max-Forwards: 70 User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Subject: Phone call Content-Length: 229 v=0 o=6000444 171 2041 IN IP4 78.26.144.10 s=Talk c=IN IP4 78.26.144.10 b=AS:380 t=0 0 m=audio 7076 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 a=rtcp:7077 IN IP4 192.168.1.107 <-------------> [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 41]: INVITE sip:6000333@209.239.114.51 SIP/2.0 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK2087609245 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 56]: From: ;tag=1085286111 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 41]: To: "Doctor" [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1783459290 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 15]: CSeq: 21 INVITE [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 44]: Contact: [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [177]: Authorization: Digest username="6000444", realm="vm.intersog.com", nonce="0d7f2bf7", uri="sip:6000333@209.239.114.51", response="6eb0c6f26c97d4159f37bb0aa0add4b7", algorithm=MD5 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 29]: Content-Type: application/sdp [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 16]: Max-Forwards: 70 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 11 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 12 [ 19]: Subject: Phone call [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 13 [ 19]: Content-Length: 229 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 14 [ 0]: [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 0 [ 3]: v=0 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 1 [ 38]: o=6000444 171 2041 IN IP4 78.26.144.10 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 2 [ 6]: s=Talk [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 3 [ 21]: c=IN IP4 78.26.144.10 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 4 [ 8]: b=AS:380 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 5 [ 5]: t=0 0 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 6 [ 26]: m=audio 7076 RTP/AVP 9 101 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 7 [ 20]: a=rtpmap:9 G722/8000 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 9 [ 15]: a=fmtp:101 0-11 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9605 parse_request: Body 10 [ 32]: a=rtcp:7077 IN IP4 192.168.1.107 --- (14 headers 11 lines) --- [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1783459290 (Checking From) --From tag 1085286111 --To-tag [May 27 17:34:48] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:27866 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.1.107:5060' into... [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.1.107' and port '5060'. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:17845 check_via: NAT detected for 192.168.1.107:5060 / 78.26.144.10:5060 Sending to 78.26.144.10:5060 (NAT) [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:24999 handle_request_invite: Initializing initreq for method INVITE - callid 1783459290 Using INVITE request as basis request - 1783459290 [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:40412' into... [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port ''. Found peer '6000444' for '6000444' from 78.26.144.10:5060 [May 27 17:34:48] DEBUG[28657][C-00000199]: rtp_engine.c:283 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7fa8701d3818' [May 27 17:34:48] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:1732 ast_rtp_new: Allocated port 10642 for RTP instance '0x7fa8701d3818' [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[28657][C-00000199]: rtp_engine.c:292 ast_rtp_instance_new: RTP instance '0x7fa8701d3818' is setup and ready to go [May 27 17:34:48] DEBUG[28657][C-00000199]: rtp_engine.c:283 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7fa8702ccaa8' [May 27 17:34:48] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:1732 ast_rtp_new: Allocated port 19938 for RTP instance '0x7fa8702ccaa8' [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[28657][C-00000199]: rtp_engine.c:292 ast_rtp_instance_new: RTP instance '0x7fa8702ccaa8' is setup and ready to go [May 27 17:34:48] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3851 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7fa8702ccaa8' == Using SIP VIDEO CoS mark 6 [May 27 17:34:48] DEBUG[28657][C-00000199]: rtp_engine.c:283 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7fa8702d1048' [May 27 17:34:48] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:1732 ast_rtp_new: Allocated port 10558 for RTP instance '0x7fa8702d1048' [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[28657][C-00000199]: rtp_engine.c:292 ast_rtp_instance_new: RTP instance '0x7fa8702d1048' is setup and ready to go [May 27 17:34:48] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3851 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7fa8702d1048' [May 27 17:34:48] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3851 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7fa8701d3818' == Using SIP RTP CoS mark 5 [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:5725 do_setnat: Setting NAT on RTP to On [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:5729 do_setnat: Setting NAT on VRTP to On [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:5737 do_setnat: Setting NAT on TRTP to On [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP o=6000444 171 2041 IN IP4 78.26.144.10... OK. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP s=Talk... UNSUPPORTED OR FAILED. [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '78.26.144.10' into... [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '78.26.144.10' and port ''. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP c=IN IP4 78.26.144.10... OK. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP b=AS:380... UNSUPPORTED OR FAILED. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. Found RTP audio format 9 [May 27 17:34:48] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 9 based on m type on 0x7fa8980c5630 Found RTP audio format 101 [May 27 17:34:48] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7fa8980c5630 Found audio description format G722 for ID 9 [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. Found audio description format telephone-event for ID 101 [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtcp:7077 IN IP4 192.168.1.107... UNSUPPORTED OR FAILED. Capabilities: us - (ulaw|g722|h264|vp8), peer - audio=(g722)/video=(nothing)/text=(nothing), combined - (g722) Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [May 27 17:34:48] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa8701d3818' Peer audio RTP is at port 78.26.144.10:7076 [May 27 17:34:48] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 9 from 0x7fa8980c5630 to 0x7fa8701d39e0 [May 27 17:34:48] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x7fa8980c5630 to 0x7fa8701d39e0 [May 27 17:34:48] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3817 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7fa8701d3818' [May 27 17:34:48] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa8702ccaa8' Peer doesn't provide video [May 27 17:34:48] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa8702d1048' Peer doesn't provide T.140 [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:10668 process_sdp: We're settling with these formats: (g722) [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:25137 handle_request_invite: Checking SIP call limits for device 6000444 [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:6669 update_call_counter: Updating call counter for incoming call [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:6774 update_call_counter: Call from peer '6000444' is 1 out of 2147483647 [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:40412' into... [May 27 17:34:48] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000444 [May 27 17:34:48] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port ''. Looking for 6000333 in webrtc (domain 209.239.114.51) [May 27 17:34:48] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000444 [May 27 17:34:48] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000444 - state 2 (In use) [May 27 17:34:48] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000444' state '2' [May 27 17:34:48] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000444' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:7906 sip_new: *** Our native formats are (g722) [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:7907 sip_new: *** Joint capabilities are (g722) [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:7908 sip_new: *** Our capabilities are (ulaw|g722|h264|vp8) [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:7909 sip_new: *** AST_CODEC_CHOOSE formats are g722 [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:7935 sip_new: This channel can handle video! HOLLYWOOD next! [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:16109 build_route: build_route: Contact hop: list_route: hop: [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:25447 handle_request_invite: SIP/6000444-000000ad: New call is still down.... Trying... <--- Transmitting (NAT) to 78.26.144.10:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.107:5060;branch=z9hG4bK2087609245;received=78.26.144.10;rport=5060 From: ;tag=1085286111 To: "Doctor" Call-ID: 1783459290 CSeq: 21 INVITE Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 100' onto UDP socket destined for 78.26.144.10:5060 [May 27 17:34:48] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000444 [May 27 17:34:48] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000444 [May 27 17:34:48] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000444 - state 2 (In use) [May 27 17:34:48] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000444' state '2' [May 27 17:34:48] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000444' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 27 17:34:48] DEBUG[20574][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:48] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. [May 27 17:34:48] DEBUG[20574][C-00000199]: pbx.c:3642 ast_str_retrieve_variable: Result of 'EXTEN' is '6000333' [May 27 17:34:48] DEBUG[20574][C-00000199]: pbx.c:4633 pbx_extension_helper: Launching 'NoOp' -- Executing [6000333@webrtc:1] NoOp("SIP/6000444-000000ad", "Call Start to: 6000333") in new stack [May 27 17:34:48] DEBUG[20574][C-00000199]: pbx.c:3642 ast_str_retrieve_variable: Result of 'EXTEN' is '6000333' [May 27 17:34:48] DEBUG[20574][C-00000199]: pbx.c:4633 pbx_extension_helper: Launching 'Dial' -- Executing [6000333@webrtc:2] Dial("SIP/6000444-000000ad", "SIP/6000333,20") in new stack [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:29402 sip_request_call: Asked to create a SIP channel with formats: (g722) [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:8721 sip_alloc: Allocating new SIP dialog for 318eec87257d8773192e079878c4d8de@209.239.114.51:5060 - INVITE (No RTP) [May 27 17:34:48] DEBUG[20574][C-00000199]: rtp_engine.c:283 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7fa87404ec18' [May 27 17:34:48] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:1732 ast_rtp_new: Allocated port 19716 for RTP instance '0x7fa87404ec18' [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[20574][C-00000199]: rtp_engine.c:292 ast_rtp_instance_new: RTP instance '0x7fa87404ec18' is setup and ready to go [May 27 17:34:48] DEBUG[20574][C-00000199]: rtp_engine.c:283 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7fa874041628' [May 27 17:34:48] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:1732 ast_rtp_new: Allocated port 15984 for RTP instance '0x7fa874041628' [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[20574][C-00000199]: rtp_engine.c:292 ast_rtp_instance_new: RTP instance '0x7fa874041628' is setup and ready to go [May 27 17:34:48] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:3851 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7fa874041628' == Using SIP VIDEO CoS mark 6 [May 27 17:34:48] DEBUG[20574][C-00000199]: rtp_engine.c:283 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7fa8740302e8' [May 27 17:34:48] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:1732 ast_rtp_new: Allocated port 14272 for RTP instance '0x7fa8740302e8' [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '209.239.114.51' into... [May 27 17:34:48] DEBUG[20574][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '209.239.114.51' and port ''. [May 27 17:34:48] DEBUG[20574][C-00000199]: rtp_engine.c:292 ast_rtp_instance_new: RTP instance '0x7fa8740302e8' is setup and ready to go [May 27 17:34:48] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:3851 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7fa8740302e8' [May 27 17:34:48] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:3851 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7fa87404ec18' == Using SIP RTP CoS mark 5 [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:5725 do_setnat: Setting NAT on RTP to On [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:5729 do_setnat: Setting NAT on VRTP to On [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:5737 do_setnat: Setting NAT on TRTP to On [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:3631 obproxy_get: OBPROXY: Not applying OBproxy to this call [May 27 17:34:48] DEBUG[20574][C-00000199]: acl.c:979 ast_ouraddrfor: For destination '89.209.100.91', our source address is '209.239.114.51'. [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:4021 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 209.239.114.51:5060 [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:7906 sip_new: *** Our native formats are (g722) [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:7907 sip_new: *** Joint capabilities are (g722) [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:7908 sip_new: *** Our capabilities are (ulaw|g722|h264|vp8) [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:7909 sip_new: *** AST_CODEC_CHOOSE formats are g722 [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:7911 sip_new: *** Our preferred formats from the incoming channel are (g722) [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:7935 sip_new: This channel can handle video! HOLLYWOOD next! [May 27 17:34:48] DEBUG[20574][C-00000199]: channel_internal_api.c:882 ast_channel_callid_set: Channel Call ID changing from [C-00000199] to [C-00000199] [May 27 17:34:48] DEBUG[20574][C-00000199]: rtp_engine.c:1685 ast_rtp_instance_early_bridge_make_compatible: Seeded SDP of 'SIP/6000333-000000ae' with that of 'SIP/6000444-000000ad' [May 27 17:34:48] DEBUG[20574][C-00000199]: channel.c:6501 ast_channel_inherit_variables: Not copying variable DIALEDTIME. [May 27 17:34:48] DEBUG[20574][C-00000199]: channel.c:6501 ast_channel_inherit_variables: Not copying variable ANSWEREDTIME. [May 27 17:34:48] DEBUG[20574][C-00000199]: channel.c:6501 ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME. [May 27 17:34:48] DEBUG[20574][C-00000199]: channel.c:6501 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER. [May 27 17:34:48] DEBUG[20574][C-00000199]: channel.c:6501 ast_channel_inherit_variables: Not copying variable DIALSTATUS. [May 27 17:34:48] DEBUG[20574][C-00000199]: channel.c:6501 ast_channel_inherit_variables: Not copying variable SIPCALLID. [May 27 17:34:48] DEBUG[20574][C-00000199]: channel.c:6501 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [May 27 17:34:48] DEBUG[20574][C-00000199]: channel.c:6501 ast_channel_inherit_variables: Not copying variable SIPURI. [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:6345 sip_call: Outgoing Call for 6000333 [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:6669 update_call_counter: Updating call counter for outgoing call [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:6774 update_call_counter: Call to peer '6000333' is 1 out of 2147483647 [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:13004 add_sdp: This call needs video offers! [May 27 17:34:48] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000333 [May 27 17:34:48] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000333 [May 27 17:34:48] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000333 - state 6 (Ringing) [May 27 17:34:48] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000333' state '6' [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:13054 add_sdp: ** Our capability: (ulaw|g722|h264|vp8) Video flag: False Text flag: False [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:13055 add_sdp: ** Our prefcodec: (g722) Audio is at 19716 Video is at 209.239.114.51:15984 [May 27 17:34:48] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000333' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Adding codec 100012 (g722) to SDP Adding codec 100003 (ulaw) to SDP Adding video codec 200006 (vp8) to SDP Adding video codec 200004 (h264) to SDP Adding non-codec 0x1 (telephone-event) to SDP [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:13192 add_sdp: -- Done with adding codecs to SDP [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:13390 add_sdp: Done building SDP. Settling with this capability: (ulaw|g722|h264|vp8) [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:3507 initialize_initreq: Initializing initreq for method INVITE - callid 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 0 [ 61]: INVITE sip:6000333@89.209.100.91;line=fb09e5769f56cfb SIP/2.0 [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK0cbe5f29;rport [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 2 [ 16]: Max-Forwards: 70 [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 3 [ 59]: From: "Patient" ;tag=as4ded556c [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 4 [ 52]: To: [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 5 [ 42]: Contact: [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 6 [ 61]: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 7 [ 16]: CSeq: 102 INVITE [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 8 [ 30]: User-Agent: Video Medicine PBX [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 9 [ 35]: Date: Mon, 27 May 2013 17:34:48 GMT [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 11 [ 26]: Supported: replaces, timer [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 12 [ 29]: Content-Type: application/sdp Reliably Transmitting (NAT) to 89.209.100.91:5060: INVITE sip:6000333@89.209.100.91;line=fb09e5769f56cfb SIP/2.0 Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK0cbe5f29;rport Max-Forwards: 70 From: "Patient" ;tag=as4ded556c To: Contact: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 102 INVITE User-Agent: Video Medicine PBX Date: Mon, 27 May 2013 17:34:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 484 v=0 o=root 1627894166 1627894166 IN IP4 209.239.114.51 s=Asterisk PBX 11.2.1 c=IN IP4 209.239.114.51 b=CT:384 t=0 0 m=audio 19716 RTP/AVP 9 0 101 a=rtpmap:9 G722/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 m=video 15984 RTP/AVP 100 99 a=rtpmap:100 VP8/90000 a=rtpmap:99 H264/90000 a=fmtp:99 redundant-pic-cap=0;parameter-add=0;packetization-mode=0;level-asymmetry-allowed=0 a=sendrecv --- [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:4324 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #432283 [May 27 17:34:48] DEBUG[20574][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 89.209.100.91:5060 -- Called SIP/6000333 <--- SIP read from UDP:89.209.100.91:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK0cbe5f29;rport=5060 From: "Patient" ;tag=as4ded556c To: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 102 INVITE User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 0 <-------------> [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 18]: SIP/2.0 100 Trying [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK0cbe5f29;rport=5060 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 59]: From: "Patient" ;tag=as4ded556c [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 52]: To: [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 61]: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 102 INVITE [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 17]: Content-Length: 0 --- (8 headers 0 lines) --- [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 (Checking To) --From tag as4ded556c --To-tag [May 27 17:34:48] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:4590 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #432283 - INVITE (got response) [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:4597 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060' Request 102: Found [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:22344 handle_response_invite: SIP response 100 to standard invite [May 27 17:34:48] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:89.209.100.91:5060 ---> SIP/2.0 101 Dialog Establishement Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK0cbe5f29;rport=5060 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 102 INVITE Contact: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 0 <-------------> [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 33]: SIP/2.0 101 Dialog Establishement [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK0cbe5f29;rport=5060 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 59]: From: "Patient" ;tag=as4ded556c [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 67]: To: ;tag=2071797323 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 61]: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 102 INVITE [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 40]: Contact: [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 17]: Content-Length: 0 --- (9 headers 0 lines) --- [May 27 17:34:48] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 (Checking To) --From tag as4ded556c --To-tag 2071797323 [May 27 17:34:48] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:4597 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060' Request 102: Found [May 27 17:34:48] DEBUG[28657][C-00000199]: chan_sip.c:22344 handle_response_invite: SIP response 101 to standard invite [May 27 17:34:48] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:89.209.100.91:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK0cbe5f29;rport=5060 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 102 INVITE Contact: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 0 <-------------> [May 27 17:34:49] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 19]: SIP/2.0 180 Ringing [May 27 17:34:49] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK0cbe5f29;rport=5060 [May 27 17:34:49] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 59]: From: "Patient" ;tag=as4ded556c [May 27 17:34:49] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 67]: To: ;tag=2071797323 [May 27 17:34:49] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 61]: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:49] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 102 INVITE [May 27 17:34:49] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 40]: Contact: [May 27 17:34:49] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:49] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 17]: Content-Length: 0 --- (9 headers 0 lines) --- [May 27 17:34:49] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 (Checking To) --From tag as4ded556c --To-tag 2071797323 [May 27 17:34:49] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:49] DEBUG[28657][C-00000199]: chan_sip.c:4597 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060' Request 102: Found [May 27 17:34:49] DEBUG[28657][C-00000199]: chan_sip.c:22344 handle_response_invite: SIP response 180 to standard invite [May 27 17:34:49] DEBUG[28657][C-00000199]: chan_sip.c:16109 build_route: build_route: Contact hop: list_route: hop: [May 27 17:34:49] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. [May 27 17:34:49] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000333 [May 27 17:34:49] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000333 [May 27 17:34:49] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000333 - state 6 (Ringing) [May 27 17:34:49] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000333' state '6' [May 27 17:34:49] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000333' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. -- SIP/6000333-000000ae is ringing [May 27 17:34:49] DEBUG[20574][C-00000199]: rtp_engine.c:1792 ast_rtp_instance_early_bridge: Setting early bridge SDP of 'SIP/6000444-000000ad' with that of 'SIP/6000333-000000ae' <--- Transmitting (NAT) to 78.26.144.10:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.1.107:5060;branch=z9hG4bK2087609245;received=78.26.144.10;rport=5060 From: ;tag=1085286111 To: "Doctor" ;tag=as0abfa1c4 Call-ID: 1783459290 CSeq: 21 INVITE Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [May 27 17:34:49] DEBUG[20574][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 180' onto UDP socket destined for 78.26.144.10:5060 <--- SIP read from UDP:89.209.100.91:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK0cbe5f29;rport=5060 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 102 INVITE Contact: Content-Type: application/sdp User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 287 v=0 o=6000333 622 2564 IN IP4 89.209.100.91 s=Talk c=IN IP4 89.209.100.91 b=AS:380 t=0 0 m=audio 7076 RTP/AVP 9 0 101 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 a=rtcp:7077 IN IP4 192.168.3.93 m=video 0 RTP/AVP 0 a=inactive <-------------> [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 14]: SIP/2.0 200 OK [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK0cbe5f29;rport=5060 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 59]: From: "Patient" ;tag=as4ded556c [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 67]: To: ;tag=2071797323 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 61]: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 102 INVITE [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 43]: Contact: [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 29]: Content-Type: application/sdp [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 19]: Content-Length: 287 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 0]: [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 0 [ 3]: v=0 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 1 [ 39]: o=6000333 622 2564 IN IP4 89.209.100.91 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 2 [ 6]: s=Talk [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 3 [ 22]: c=IN IP4 89.209.100.91 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 4 [ 8]: b=AS:380 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 5 [ 5]: t=0 0 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 6 [ 28]: m=audio 7076 RTP/AVP 9 0 101 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 7 [ 20]: a=rtpmap:9 G722/8000 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 8 [ 20]: a=rtpmap:0 PCMU/8000 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 10 [ 15]: a=fmtp:101 0-11 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 11 [ 31]: a=rtcp:7077 IN IP4 192.168.3.93 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 12 [ 19]: m=video 0 RTP/AVP 0 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9605 parse_request: Body 13 [ 10]: a=inactive --- (10 headers 14 lines) --- [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 (Checking To) --From tag as4ded556c --To-tag 2071797323 [May 27 17:34:51] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:4518 __sip_ack: Acked pending invite 102 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:4556 __sip_ack: Stopping retransmission on '298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060' of Request 102: Match Found [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:22344 handle_response_invite: SIP response 200 to standard invite [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP o=6000333 622 2564 IN IP4 89.209.100.91... OK. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP s=Talk... UNSUPPORTED OR FAILED. [May 27 17:34:51] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '89.209.100.91' into... [May 27 17:34:51] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '89.209.100.91' and port ''. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP c=IN IP4 89.209.100.91... OK. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP b=AS:380... UNSUPPORTED OR FAILED. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. Found RTP audio format 9 [May 27 17:34:51] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 9 based on m type on 0x7fa8980c4ad0 Found RTP audio format 0 [May 27 17:34:51] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 0 based on m type on 0x7fa8980c4ad0 Found RTP audio format 101 [May 27 17:34:51] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7fa8980c4ad0 Found audio description format G722 for ID 9 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. Found audio description format PCMU for ID 0 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. Found audio description format telephone-event for ID 101 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtcp:7077 IN IP4 192.168.3.93... UNSUPPORTED OR FAILED. [May 27 17:34:51] WARNING[28657][C-00000199]: chan_sip.c:10131 process_sdp: Ignoring video stream offer because port number is zero Capabilities: us - (ulaw|g722|h264|vp8), peer - audio=(ulaw|g722)/video=(nothing)/text=(nothing), combined - (ulaw|g722) Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [May 27 17:34:51] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa87404ec18' Peer audio RTP is at port 89.209.100.91:7076 [May 27 17:34:51] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 0 from 0x7fa8980c4ad0 to 0x7fa87404ede0 [May 27 17:34:51] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 9 from 0x7fa8980c4ad0 to 0x7fa87404ede0 [May 27 17:34:51] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x7fa8980c4ad0 to 0x7fa87404ede0 [May 27 17:34:51] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3817 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7fa87404ec18' [May 27 17:34:51] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa874041628' Peer doesn't provide video [May 27 17:34:51] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa8740302e8' Peer doesn't provide T.140 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10668 process_sdp: We're settling with these formats: (ulaw|g722) [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10675 process_sdp: We have an owner, now see if we need to change this call [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10681 process_sdp: Setting native formats after processing SDP. peer joint formats (ulaw|g722), old nativeformats (g722) [May 27 17:34:51] DEBUG[28657][C-00000199]: channel.c:5355 set_format: Set channel SIP/6000333-000000ae to read format g722 [May 27 17:34:51] DEBUG[28657][C-00000199]: channel.c:5355 set_format: Set channel SIP/6000333-000000ae to write format g722 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:6669 update_call_counter: Updating call counter for outgoing call [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:16109 build_route: build_route: Contact hop: list_route: hop: [May 27 17:34:51] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000333 [May 27 17:34:51] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000333 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:11802 reqprep: Strict routing enforced for session 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:51] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000333 - state 2 (In use) [May 27 17:34:51] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000333' state '2' set_destination: Parsing for address/port to send to [May 27 17:34:51] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.3.93' into... [May 27 17:34:51] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.3.93' and port ''. set_destination: set destination to 192.168.3.93:5060 [May 27 17:34:51] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000333' changed to state '2' (In use) but we don't care because they're not a member of any queue. Transmitting (NAT) to 89.209.100.91:5060: ACK sip:linphone.iphone@192.168.3.93 SIP/2.0 Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK7d927cb6;rport Max-Forwards: 70 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Contact: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 102 ACK User-Agent: Video Medicine PBX Content-Length: 0 --- [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'ACK sip:lin' onto UDP socket destined for 89.209.100.91:5060 [May 27 17:34:51] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. -- SIP/6000333-000000ae answered SIP/6000444-000000ad [May 27 17:34:51] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000333 [May 27 17:34:51] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000333 [May 27 17:34:51] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000333 - state 2 (In use) [May 27 17:34:51] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000333' state '2' [May 27 17:34:51] DEBUG[20574][C-00000199]: rtp_engine.c:1792 ast_rtp_instance_early_bridge: Setting early bridge SDP of 'SIP/6000444-000000ad' with that of 'SIP/6000333-000000ae' [May 27 17:34:51] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000333' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:7256 sip_answer: SIP answering channel: SIP/6000444-000000ad [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:2085 ast_rtp_update_source: Setting the marker bit due to a source update [May 27 17:34:51] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000444 [May 27 17:34:51] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000444 [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:13504 transmit_response_with_sdp: Setting framing from config on incoming call [May 27 17:34:51] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000444 - state 2 (In use) [May 27 17:34:51] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000444' state '2' [May 27 17:34:51] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000444' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:13054 add_sdp: ** Our capability: (g722) Video flag: True Text flag: True [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:13055 add_sdp: ** Our prefcodec: (nothing) Audio is at 10642 Adding codec 100012 (g722) to SDP Adding non-codec 0x1 (telephone-event) to SDP [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:13192 add_sdp: -- Done with adding codecs to SDP [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:13390 add_sdp: Done building SDP. Settling with this capability: (g722) <--- Reliably Transmitting (NAT) to 78.26.144.10:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.107:5060;branch=z9hG4bK2087609245;received=78.26.144.10;rport=5060 From: ;tag=1085286111 To: "Doctor" ;tag=as0abfa1c4 Call-ID: 1783459290 CSeq: 21 INVITE Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 266 v=0 o=root 1912678123 1912678123 IN IP4 209.239.114.51 s=Asterisk PBX 11.2.1 c=IN IP4 209.239.114.51 t=0 0 m=audio 10642 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 <------------> [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:4324 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #432286 [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 78.26.144.10:5060 [May 27 17:34:51] DEBUG[20574][C-00000199]: features.c:4410 ast_bridge_call: bridge answer set, chan answer set [May 27 17:34:51] DEBUG[20574][C-00000199]: features.c:4234 clear_dialed_interfaces: Removing dialed interfaces datastore on SIP/6000333-000000ae since we're bridging [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:2085 ast_rtp_update_source: Setting the marker bit due to a source update [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:2085 ast_rtp_update_source: Setting the marker bit due to a source update -- Remotely bridging SIP/6000444-000000ad and SIP/6000333-000000ae [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:32435 sip_set_rtp_peer: Deferring reinvite on SIP '1783459290' - It's audio will be redirected to IP 89.209.100.91:7076 [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:32432 sip_set_rtp_peer: Sending reinvite on SIP '298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060' - It's audio soon redirected to IP 78.26.144.10:7076 [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:11802 reqprep: Strict routing enforced for session 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 set_destination: Parsing for address/port to send to [May 27 17:34:51] DEBUG[20574][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.3.93' into... [May 27 17:34:51] DEBUG[20574][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.3.93' and port ''. set_destination: set destination to 192.168.3.93:5060 [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:13054 add_sdp: ** Our capability: (ulaw|g722) Video flag: True Text flag: True [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:13055 add_sdp: ** Our prefcodec: (g722) [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:13059 add_sdp: ** Our native-bridge filtered capablity: (g722) Audio is at 19716 Adding codec 100012 (g722) to SDP Adding non-codec 0x1 (telephone-event) to SDP [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:13192 add_sdp: -- Done with adding codecs to SDP [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:13390 add_sdp: Done building SDP. Settling with this capability: (g722) [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:3505 initialize_initreq: Initializing already initialized SIP dialog 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 (presumably reinvite) [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 0 [ 47]: INVITE sip:linphone.iphone@192.168.3.93 SIP/2.0 [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK10eb51a9;rport [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 2 [ 16]: Max-Forwards: 70 [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 3 [ 59]: From: "Patient" ;tag=as4ded556c [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 4 [ 67]: To: ;tag=2071797323 [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 5 [ 42]: Contact: [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 6 [ 61]: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 7 [ 16]: CSeq: 103 INVITE [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 8 [ 30]: User-Agent: Video Medicine PBX [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 10 [ 26]: Supported: replaces, timer [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 12 [ 29]: Content-Type: application/sdp Reliably Transmitting (NAT) to 89.209.100.91:5060: INVITE sip:linphone.iphone@192.168.3.93 SIP/2.0 Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK10eb51a9;rport Max-Forwards: 70 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Contact: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 103 INVITE User-Agent: Video Medicine PBX 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: 261 v=0 o=root 1627894166 1627894167 IN IP4 78.26.144.10 s=Asterisk PBX 11.2.1 c=IN IP4 78.26.144.10 t=0 0 m=audio 7076 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 --- [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:4324 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #432287 [May 27 17:34:51] DEBUG[20574][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 89.209.100.91:5060 [May 27 17:34:51] DEBUG[20574][C-00000199]: rtp_engine.c:1278 remote_bridge_loop: Oooh, 'SIP/6000444-000000ad' changed end address to 78.26.144.10:7076 (format (g722)) [May 27 17:34:51] DEBUG[20574][C-00000199]: rtp_engine.c:1281 remote_bridge_loop: Oooh, 'SIP/6000444-000000ad' was 78.26.144.10:7076/(format (g722)) <--- SIP read from UDP:89.209.100.91:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK10eb51a9;rport=5060 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 103 INVITE User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 0 <-------------> [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 18]: SIP/2.0 100 Trying [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK10eb51a9;rport=5060 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 59]: From: "Patient" ;tag=as4ded556c [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 67]: To: ;tag=2071797323 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 61]: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 103 INVITE [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 17]: Content-Length: 0 --- (8 headers 0 lines) --- [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 (Checking To) --From tag as4ded556c --To-tag 2071797323 [May 27 17:34:51] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:4590 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #432287 - INVITE (got response) [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:4597 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060' Request 103: Found [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:22342 handle_response_invite: SIP response 100 to RE-invite on outgoing call 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:51] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:78.26.144.10:5060 ---> ACK sip:6000333@209.239.114.51:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK1441941409 From: ;tag=1085286111 To: "Doctor" ;tag=as0abfa1c4 Call-ID: 1783459290 CSeq: 21 ACK Contact: Max-Forwards: 70 User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 0 <-------------> [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 43]: ACK sip:6000333@209.239.114.51:5060 SIP/2.0 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK1441941409 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 56]: From: ;tag=1085286111 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 56]: To: "Doctor" ;tag=as0abfa1c4 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1783459290 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 12]: CSeq: 21 ACK [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 43]: Contact: [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 16]: Max-Forwards: 70 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 17]: Content-Length: 0 --- (10 headers 0 lines) --- [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1783459290 (Checking From) --From tag 1085286111 --To-tag as0abfa1c4 [May 27 17:34:51] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:27866 handle_incoming: **** Received ACK (6) - Command in SIP ACK [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:4523 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #432286 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:4556 __sip_ack: Stopping retransmission on '1783459290' of Response 21: Match Found [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:22145 check_pendings: Sending pending reinvite on '1783459290' [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:11802 reqprep: Strict routing enforced for session 1783459290 set_destination: Parsing for address/port to send to [May 27 17:34:51] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.1.107' into... [May 27 17:34:51] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.1.107' and port ''. set_destination: set destination to 192.168.1.107:5060 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:13054 add_sdp: ** Our capability: (g722) Video flag: True Text flag: True [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:13055 add_sdp: ** Our prefcodec: (nothing) [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:13059 add_sdp: ** Our native-bridge filtered capablity: (g722) Audio is at 10642 Adding codec 100012 (g722) to SDP Adding non-codec 0x1 (telephone-event) to SDP [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:13192 add_sdp: -- Done with adding codecs to SDP [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:13390 add_sdp: Done building SDP. Settling with this capability: (g722) [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:3505 initialize_initreq: Initializing already initialized SIP dialog 1783459290 (presumably reinvite) [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 0 [ 48]: INVITE sip:linphone.iphone@192.168.1.107 SIP/2.0 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK1c579220;rport [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 2 [ 16]: Max-Forwards: 70 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 3 [ 58]: From: "Doctor" ;tag=as0abfa1c4 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 4 [ 54]: To: ;tag=1085286111 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 5 [ 42]: Contact: [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 6 [ 19]: Call-ID: 1783459290 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 7 [ 16]: CSeq: 102 INVITE [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 8 [ 30]: User-Agent: Video Medicine PBX [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 10 [ 26]: Supported: replaces, timer [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:9568 parse_request: Header 12 [ 29]: Content-Type: application/sdp Reliably Transmitting (NAT) to 78.26.144.10:5060: INVITE sip:linphone.iphone@192.168.1.107 SIP/2.0 Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK1c579220;rport Max-Forwards: 70 From: "Doctor" ;tag=as0abfa1c4 To: ;tag=1085286111 Contact: Call-ID: 1783459290 CSeq: 102 INVITE User-Agent: Video Medicine PBX 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: 263 v=0 o=root 1912678123 1912678124 IN IP4 89.209.100.91 s=Asterisk PBX 11.2.1 c=IN IP4 89.209.100.91 t=0 0 m=audio 7076 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 --- [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:4324 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #432288 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 78.26.144.10:5060 [May 27 17:34:51] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:3502 ast_rtp_read: 0x7fa8701b1dc0 -- start learning mode pass with addr = 78.26.144.10:7076 [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:1605 rtp_learning_rtp_seq_update: 0x7fa8701b1dc0 -- probation = 4, seq = 0 [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:3508 ast_rtp_read: 0x7fa8701b1dc0 -- Condition for learning hasn't exited, so reject the frame. [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:3502 ast_rtp_read: 0x7fa8701b1dc0 -- start learning mode pass with addr = 78.26.144.10:7076 [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:1605 rtp_learning_rtp_seq_update: 0x7fa8701b1dc0 -- probation = 3, seq = 1 [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:3508 ast_rtp_read: 0x7fa8701b1dc0 -- Condition for learning hasn't exited, so reject the frame. [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:3502 ast_rtp_read: 0x7fa8701b1dc0 -- start learning mode pass with addr = 78.26.144.10:7076 [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:1605 rtp_learning_rtp_seq_update: 0x7fa8701b1dc0 -- probation = 2, seq = 2 [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:3508 ast_rtp_read: 0x7fa8701b1dc0 -- Condition for learning hasn't exited, so reject the frame. [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:3502 ast_rtp_read: 0x7fa8701b1dc0 -- start learning mode pass with addr = 78.26.144.10:7076 [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:1605 rtp_learning_rtp_seq_update: 0x7fa8701b1dc0 -- probation = 1, seq = 3 [May 27 17:34:51] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:3512 ast_rtp_read: 0x7fa8701b1dc0 -- Probation Ended. Set strict_rtp_state to STRICT_RTP_CLOSED with address 78.26.144.10:7076 <--- SIP read from UDP:78.26.144.10:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK1c579220;rport=5060 From: "Doctor" ;tag=as0abfa1c4 To: ;tag=1085286111 Call-ID: 1783459290 CSeq: 102 INVITE User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 0 <-------------> [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 18]: SIP/2.0 100 Trying [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK1c579220;rport=5060 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 58]: From: "Doctor" ;tag=as0abfa1c4 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 54]: To: ;tag=1085286111 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1783459290 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 102 INVITE [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 17]: Content-Length: 0 --- (8 headers 0 lines) --- [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1783459290 (Checking To) --From tag as0abfa1c4 --To-tag 1085286111 [May 27 17:34:51] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:4590 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #432288 - INVITE (got response) [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:4597 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '1783459290' Request 102: Found [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:22342 handle_response_invite: SIP response 100 to RE-invite on outgoing call 1783459290 [May 27 17:34:51] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:78.26.144.10:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK1c579220;rport=5060 From: "Doctor" ;tag=as0abfa1c4 To: ;tag=1085286111 Call-ID: 1783459290 CSeq: 102 INVITE Contact: Content-Type: application/sdp User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 229 v=0 o=6000444 171 2042 IN IP4 78.26.144.10 s=Talk c=IN IP4 78.26.144.10 b=AS:380 t=0 0 m=audio 7076 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 a=rtcp:7077 IN IP4 192.168.1.107 <-------------> [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 14]: SIP/2.0 200 OK [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK1c579220;rport=5060 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 58]: From: "Doctor" ;tag=as0abfa1c4 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 54]: To: ;tag=1085286111 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1783459290 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 102 INVITE [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 43]: Contact: [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 29]: Content-Type: application/sdp [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 19]: Content-Length: 229 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 0]: [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 0 [ 3]: v=0 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 1 [ 38]: o=6000444 171 2042 IN IP4 78.26.144.10 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 2 [ 6]: s=Talk [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 3 [ 21]: c=IN IP4 78.26.144.10 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 4 [ 8]: b=AS:380 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 5 [ 5]: t=0 0 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 6 [ 26]: m=audio 7076 RTP/AVP 9 101 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 7 [ 20]: a=rtpmap:9 G722/8000 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 9 [ 15]: a=fmtp:101 0-11 [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9605 parse_request: Body 10 [ 32]: a=rtcp:7077 IN IP4 192.168.1.107 --- (10 headers 11 lines) --- [May 27 17:34:51] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1783459290 (Checking To) --From tag as0abfa1c4 --To-tag 1085286111 [May 27 17:34:51] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:4518 __sip_ack: Acked pending invite 102 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:4556 __sip_ack: Stopping retransmission on '1783459290' of Request 102: Match Found [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:22342 handle_response_invite: SIP response 200 to RE-invite on outgoing call 1783459290 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP o=6000444 171 2042 IN IP4 78.26.144.10... OK. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP s=Talk... UNSUPPORTED OR FAILED. [May 27 17:34:51] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '78.26.144.10' into... [May 27 17:34:51] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '78.26.144.10' and port ''. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP c=IN IP4 78.26.144.10... OK. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP b=AS:380... UNSUPPORTED OR FAILED. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. Found RTP audio format 9 [May 27 17:34:51] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 9 based on m type on 0x7fa8980c4ad0 Found RTP audio format 101 [May 27 17:34:51] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7fa8980c4ad0 Found audio description format G722 for ID 9 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. Found audio description format telephone-event for ID 101 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED. [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtcp:7077 IN IP4 192.168.1.107... UNSUPPORTED OR FAILED. Capabilities: us - (ulaw|g722|h264|vp8), peer - audio=(g722)/video=(nothing)/text=(nothing), combined - (g722) Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) Peer audio RTP is at port 78.26.144.10:7076 [May 27 17:34:51] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 9 from 0x7fa8980c4ad0 to 0x7fa8701d39e0 [May 27 17:34:51] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x7fa8980c4ad0 to 0x7fa8701d39e0 [May 27 17:34:51] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3851 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7fa8701d3818' Peer doesn't provide video [May 27 17:34:51] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa8702d1048' Peer doesn't provide T.140 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10668 process_sdp: We're settling with these formats: (g722) [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10675 process_sdp: We have an owner, now see if we need to change this call [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:10681 process_sdp: Setting native formats after processing SDP. peer joint formats (g722), old nativeformats (g722) [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:6669 update_call_counter: Updating call counter for incoming call [May 27 17:34:51] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000444 [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:11802 reqprep: Strict routing enforced for session 1783459290 [May 27 17:34:51] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000444 set_destination: Parsing for address/port to send to [May 27 17:34:51] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000444 - state 2 (In use) [May 27 17:34:51] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000444' state '2' [May 27 17:34:51] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.1.107' into... [May 27 17:34:51] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.1.107' and port ''. set_destination: set destination to 192.168.1.107:5060 [May 27 17:34:51] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000444' changed to state '2' (In use) but we don't care because they're not a member of any queue. Transmitting (NAT) to 78.26.144.10:5060: ACK sip:linphone.iphone@192.168.1.107 SIP/2.0 Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK02114384;rport Max-Forwards: 70 From: "Doctor" ;tag=as0abfa1c4 To: ;tag=1085286111 Contact: Call-ID: 1783459290 CSeq: 102 ACK User-Agent: Video Medicine PBX Content-Length: 0 --- [May 27 17:34:51] DEBUG[28657][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'ACK sip:lin' onto UDP socket destined for 78.26.144.10:5060 [May 27 17:34:51] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:78.26.144.10:5060 ---> REGISTER sip:vm.intersog.com:40412 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK929311473 From: ;tag=1180148849 To: Call-ID: 1620343365 CSeq: 11 REGISTER Contact: Max-Forwards: 70 User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Expires: 60 Content-Length: 0 <-------------> [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 42]: REGISTER sip:vm.intersog.com:40412 SIP/2.0 [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK929311473 [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 56]: From: ;tag=1180148849 [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 39]: To: [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1620343365 [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 17]: CSeq: 11 REGISTER [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 61]: Contact: [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 16]: Max-Forwards: 70 [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 11]: Expires: 60 [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 17]: Content-Length: 0 --- (11 headers 0 lines) --- [May 27 17:34:52] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1620343365 (Checking From) --From tag 1180148849 --To-tag [May 27 17:34:52] DEBUG[28657]: acl.c:979 ast_ouraddrfor: For destination '78.26.144.10', our source address is '209.239.114.51'. [May 27 17:34:52] DEBUG[28657]: chan_sip.c:4021 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 209.239.114.51:5060 [May 27 17:34:52] DEBUG[28657]: chan_sip.c:8721 sip_alloc: Allocating new SIP dialog for 1620343365 - REGISTER (No RTP) [May 27 17:34:52] DEBUG[28657]: chan_sip.c:27866 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER [May 27 17:34:52] DEBUG[28657]: chan_sip.c:27689 handle_request_register: Initializing initreq for method REGISTER - callid 1620343365 [May 27 17:34:52] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.1.107:5060' into... [May 27 17:34:52] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.1.107' and port '5060'. [May 27 17:34:52] DEBUG[28657]: chan_sip.c:17845 check_via: NAT detected for 192.168.1.107:5060 / 78.26.144.10:5060 Sending to 78.26.144.10:5060 (NAT) [May 27 17:34:52] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:40412' into... [May 27 17:34:52] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port ''. <--- Transmitting (NAT) to 78.26.144.10:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.107:5060;branch=z9hG4bK929311473;received=78.26.144.10;rport=5060 From: ;tag=1180148849 To: ;tag=as1a6940a0 Call-ID: 1620343365 CSeq: 11 REGISTER Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="vm.intersog.com", nonce="69d2fb5a" Content-Length: 0 <------------> [May 27 17:34:52] DEBUG[28657]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 78.26.144.10:5060 Scheduling destruction of SIP dialog '1620343365' in 32000 ms (Method: REGISTER) <--- SIP read from UDP:78.26.144.10:5060 ---> REGISTER sip:vm.intersog.com:40412 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK515008461 From: ;tag=1180148849 To: Call-ID: 1620343365 CSeq: 12 REGISTER Contact: Authorization: Digest username="6000444", realm="vm.intersog.com", nonce="69d2fb5a", uri="sip:vm.intersog.com:40412", response="7f7a296f1e66ccd493fe7498b0bbedba", algorithm=MD5 Max-Forwards: 70 User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Expires: 60 Content-Length: 0 <-------------> [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 42]: REGISTER sip:vm.intersog.com:40412 SIP/2.0 [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK515008461 [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 56]: From: ;tag=1180148849 [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 39]: To: [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1620343365 [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 17]: CSeq: 12 REGISTER [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 61]: Contact: [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [176]: Authorization: Digest username="6000444", realm="vm.intersog.com", nonce="69d2fb5a", uri="sip:vm.intersog.com:40412", response="7f7a296f1e66ccd493fe7498b0bbedba", algorithm=MD5 [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 16]: Max-Forwards: 70 [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 11]: Expires: 60 [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 11 [ 17]: Content-Length: 0 --- (12 headers 0 lines) --- [May 27 17:34:53] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1620343365 (Checking From) --From tag 1180148849 --To-tag [May 27 17:34:53] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:40412' into... [May 27 17:34:53] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port '40412'. [May 27 17:34:53] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:40412' into... [May 27 17:34:53] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port '40412'. [May 27 17:34:53] DEBUG[28657]: chan_sip.c:27866 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER [May 27 17:34:53] DEBUG[28657]: chan_sip.c:27689 handle_request_register: Initializing initreq for method REGISTER - callid 1620343365 [May 27 17:34:53] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.1.107:5060' into... [May 27 17:34:53] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.1.107' and port '5060'. [May 27 17:34:53] DEBUG[28657]: chan_sip.c:17845 check_via: NAT detected for 192.168.1.107:5060 / 78.26.144.10:5060 Sending to 78.26.144.10:5060 (NAT) [May 27 17:34:53] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:40412' into... [May 27 17:34:53] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port ''. [May 27 17:34:53] DEBUG[28657]: chan_sip.c:15927 parse_register_contact: Store REGISTER's src-IP:port for call routing. <--- Transmitting (NAT) to 78.26.144.10:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.107:5060;branch=z9hG4bK515008461;received=78.26.144.10;rport=5060 From: ;tag=1180148849 To: ;tag=as1a6940a0 Call-ID: 1620343365 CSeq: 12 REGISTER Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Expires: 60 Contact: ;expires=60 Date: Mon, 27 May 2013 17:34:53 GMT Content-Length: 0 <------------> [May 27 17:34:53] DEBUG[28657]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 78.26.144.10:5060 [May 27 17:34:53] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000444 [May 27 17:34:53] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000444 [May 27 17:34:53] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000444 - state 2 (In use) [May 27 17:34:53] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000444' state '2' [May 27 17:34:53] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000444' changed to state '2' (In use) but we don't care because they're not a member of any queue. Scheduling destruction of SIP dialog '1620343365' in 32000 ms (Method: REGISTER) <--- SIP read from UDP:89.209.100.91:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK10eb51a9;rport=5060 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 103 INVITE Contact: Content-Type: application/sdp User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 230 v=0 o=6000333 622 2565 IN IP4 89.209.100.91 s=Talk c=IN IP4 89.209.100.91 b=AS:380 t=0 0 m=audio 7076 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 a=rtcp:7077 IN IP4 192.168.3.93 <-------------> [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 14]: SIP/2.0 200 OK [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK10eb51a9;rport=5060 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 59]: From: "Patient" ;tag=as4ded556c [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 67]: To: ;tag=2071797323 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 61]: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 103 INVITE [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 43]: Contact: [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 29]: Content-Type: application/sdp [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 19]: Content-Length: 230 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 0]: [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 0 [ 3]: v=0 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 1 [ 39]: o=6000333 622 2565 IN IP4 89.209.100.91 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 2 [ 6]: s=Talk [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 3 [ 22]: c=IN IP4 89.209.100.91 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 4 [ 8]: b=AS:380 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 5 [ 5]: t=0 0 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 6 [ 26]: m=audio 7076 RTP/AVP 9 101 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 7 [ 20]: a=rtpmap:9 G722/8000 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 9 [ 15]: a=fmtp:101 0-11 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9605 parse_request: Body 10 [ 31]: a=rtcp:7077 IN IP4 192.168.3.93 --- (10 headers 11 lines) --- [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 (Checking To) --From tag as4ded556c --To-tag 2071797323 [May 27 17:34:54] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:4518 __sip_ack: Acked pending invite 103 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:4556 __sip_ack: Stopping retransmission on '298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060' of Request 103: Match Found [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:22342 handle_response_invite: SIP response 200 to RE-invite on outgoing call 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP o=6000333 622 2565 IN IP4 89.209.100.91... OK. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP s=Talk... UNSUPPORTED OR FAILED. [May 27 17:34:54] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '89.209.100.91' into... [May 27 17:34:54] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '89.209.100.91' and port ''. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP c=IN IP4 89.209.100.91... OK. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP b=AS:380... UNSUPPORTED OR FAILED. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. Found RTP audio format 9 [May 27 17:34:54] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 9 based on m type on 0x7fa8980c4ad0 Found RTP audio format 101 [May 27 17:34:54] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7fa8980c4ad0 Found audio description format G722 for ID 9 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. Found audio description format telephone-event for ID 101 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtcp:7077 IN IP4 192.168.3.93... UNSUPPORTED OR FAILED. Capabilities: us - (ulaw|g722|h264|vp8), peer - audio=(g722)/video=(nothing)/text=(nothing), combined - (g722) Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) Peer audio RTP is at port 89.209.100.91:7076 [May 27 17:34:54] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 9 from 0x7fa8980c4ad0 to 0x7fa87404ede0 [May 27 17:34:54] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x7fa8980c4ad0 to 0x7fa87404ede0 [May 27 17:34:54] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3851 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7fa87404ec18' Peer doesn't provide video [May 27 17:34:54] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa8740302e8' Peer doesn't provide T.140 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10668 process_sdp: We're settling with these formats: (g722) [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10675 process_sdp: We have an owner, now see if we need to change this call [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10681 process_sdp: Setting native formats after processing SDP. peer joint formats (g722), old nativeformats (ulaw) [May 27 17:34:54] DEBUG[28657][C-00000199]: channel.c:5355 set_format: Set channel SIP/6000333-000000ae to read format g722 [May 27 17:34:54] DEBUG[28657][C-00000199]: channel.c:5355 set_format: Set channel SIP/6000333-000000ae to write format g722 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:6669 update_call_counter: Updating call counter for outgoing call [May 27 17:34:54] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000333 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:11802 reqprep: Strict routing enforced for session 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:54] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000333 set_destination: Parsing for address/port to send to [May 27 17:34:54] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000333 - state 2 (In use) [May 27 17:34:54] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.3.93' into... [May 27 17:34:54] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000333' state '2' [May 27 17:34:54] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.3.93' and port ''. set_destination: set destination to 192.168.3.93:5060 Transmitting (NAT) to 89.209.100.91:5060: ACK sip:linphone.iphone@192.168.3.93 SIP/2.0 Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK269b3945;rport Max-Forwards: 70 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Contact: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 103 ACK User-Agent: Video Medicine PBX Content-Length: 0 --- [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'ACK sip:lin' onto UDP socket destined for 89.209.100.91:5060 [May 27 17:34:54] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000333' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 27 17:34:54] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. [May 27 17:34:54] DEBUG[20574][C-00000199]: rtp_engine.c:1243 remote_bridge_loop: Oooh, 'SIP/6000333-000000ae' changed end address to 89.209.100.91:7076 (format (g722)) [May 27 17:34:54] DEBUG[20574][C-00000199]: rtp_engine.c:1246 remote_bridge_loop: Oooh, 'SIP/6000333-000000ae' changed end vaddress to (null) (format (g722)) [May 27 17:34:54] DEBUG[20574][C-00000199]: rtp_engine.c:1249 remote_bridge_loop: Oooh, 'SIP/6000333-000000ae' changed end taddress to (null) (format (g722)) [May 27 17:34:54] DEBUG[20574][C-00000199]: rtp_engine.c:1252 remote_bridge_loop: Oooh, 'SIP/6000333-000000ae' was 89.209.100.91:7076/(format (ulaw|g722)) [May 27 17:34:54] DEBUG[20574][C-00000199]: rtp_engine.c:1255 remote_bridge_loop: Oooh, 'SIP/6000333-000000ae' was (null)/(format (ulaw|g722)) [May 27 17:34:54] DEBUG[20574][C-00000199]: rtp_engine.c:1258 remote_bridge_loop: Oooh, 'SIP/6000333-000000ae' was (null)/(format (ulaw|g722)) [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:32432 sip_set_rtp_peer: Sending reinvite on SIP '1783459290' - It's audio soon redirected to IP 89.209.100.91:7076 [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:11802 reqprep: Strict routing enforced for session 1783459290 set_destination: Parsing for address/port to send to [May 27 17:34:54] DEBUG[20574][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.1.107' into... [May 27 17:34:54] DEBUG[20574][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.1.107' and port ''. set_destination: set destination to 192.168.1.107:5060 [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:13054 add_sdp: ** Our capability: (g722) Video flag: True Text flag: True [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:13055 add_sdp: ** Our prefcodec: (nothing) [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:13059 add_sdp: ** Our native-bridge filtered capablity: (g722) Audio is at 10642 Adding codec 100012 (g722) to SDP Adding non-codec 0x1 (telephone-event) to SDP [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:13192 add_sdp: -- Done with adding codecs to SDP [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:13390 add_sdp: Done building SDP. Settling with this capability: (g722) [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:3505 initialize_initreq: Initializing already initialized SIP dialog 1783459290 (presumably reinvite) [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 0 [ 48]: INVITE sip:linphone.iphone@192.168.1.107 SIP/2.0 [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK68137f30;rport [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 2 [ 16]: Max-Forwards: 70 [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 3 [ 58]: From: "Doctor" ;tag=as0abfa1c4 [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 4 [ 54]: To: ;tag=1085286111 [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 5 [ 42]: Contact: [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 6 [ 19]: Call-ID: 1783459290 [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 7 [ 16]: CSeq: 103 INVITE [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 8 [ 30]: User-Agent: Video Medicine PBX [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 10 [ 26]: Supported: replaces, timer [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 12 [ 29]: Content-Type: application/sdp Reliably Transmitting (NAT) to 78.26.144.10:5060: INVITE sip:linphone.iphone@192.168.1.107 SIP/2.0 Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK68137f30;rport Max-Forwards: 70 From: "Doctor" ;tag=as0abfa1c4 To: ;tag=1085286111 Contact: Call-ID: 1783459290 CSeq: 103 INVITE User-Agent: Video Medicine PBX 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: 263 v=0 o=root 1912678123 1912678125 IN IP4 89.209.100.91 s=Asterisk PBX 11.2.1 c=IN IP4 89.209.100.91 t=0 0 m=audio 7076 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 --- [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:4324 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #432292 [May 27 17:34:54] DEBUG[20574][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 78.26.144.10:5060 <--- SIP read from UDP:78.26.144.10:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK68137f30;rport=5060 From: "Doctor" ;tag=as0abfa1c4 To: ;tag=1085286111 Call-ID: 1783459290 CSeq: 103 INVITE User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 0 <-------------> [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 18]: SIP/2.0 100 Trying [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK68137f30;rport=5060 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 58]: From: "Doctor" ;tag=as0abfa1c4 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 54]: To: ;tag=1085286111 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1783459290 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 103 INVITE [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 17]: Content-Length: 0 --- (8 headers 0 lines) --- [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1783459290 (Checking To) --From tag as0abfa1c4 --To-tag 1085286111 [May 27 17:34:54] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:4590 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #432292 - INVITE (got response) [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:4597 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '1783459290' Request 103: Found [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:22342 handle_response_invite: SIP response 100 to RE-invite on outgoing call 1783459290 [May 27 17:34:54] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:78.26.144.10:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK68137f30;rport=5060 From: "Doctor" ;tag=as0abfa1c4 To: ;tag=1085286111 Call-ID: 1783459290 CSeq: 103 INVITE Contact: Content-Type: application/sdp User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 229 v=0 o=6000444 171 2043 IN IP4 78.26.144.10 s=Talk c=IN IP4 78.26.144.10 b=AS:380 t=0 0 m=audio 7076 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 a=rtcp:7077 IN IP4 192.168.1.107 <-------------> [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 14]: SIP/2.0 200 OK [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK68137f30;rport=5060 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 58]: From: "Doctor" ;tag=as0abfa1c4 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 54]: To: ;tag=1085286111 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1783459290 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 103 INVITE [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 43]: Contact: [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 29]: Content-Type: application/sdp [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 19]: Content-Length: 229 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 0]: [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 0 [ 3]: v=0 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 1 [ 38]: o=6000444 171 2043 IN IP4 78.26.144.10 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 2 [ 6]: s=Talk [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 3 [ 21]: c=IN IP4 78.26.144.10 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 4 [ 8]: b=AS:380 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 5 [ 5]: t=0 0 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 6 [ 26]: m=audio 7076 RTP/AVP 9 101 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 7 [ 20]: a=rtpmap:9 G722/8000 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 9 [ 15]: a=fmtp:101 0-11 [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9605 parse_request: Body 10 [ 32]: a=rtcp:7077 IN IP4 192.168.1.107 --- (10 headers 11 lines) --- [May 27 17:34:54] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1783459290 (Checking To) --From tag as0abfa1c4 --To-tag 1085286111 [May 27 17:34:54] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:4518 __sip_ack: Acked pending invite 103 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:4556 __sip_ack: Stopping retransmission on '1783459290' of Request 103: Match Found [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:22342 handle_response_invite: SIP response 200 to RE-invite on outgoing call 1783459290 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP o=6000444 171 2043 IN IP4 78.26.144.10... OK. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP s=Talk... UNSUPPORTED OR FAILED. [May 27 17:34:54] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '78.26.144.10' into... [May 27 17:34:54] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '78.26.144.10' and port ''. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP c=IN IP4 78.26.144.10... OK. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP b=AS:380... UNSUPPORTED OR FAILED. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. Found RTP audio format 9 [May 27 17:34:54] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 9 based on m type on 0x7fa8980c4ad0 Found RTP audio format 101 [May 27 17:34:54] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7fa8980c4ad0 Found audio description format G722 for ID 9 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. Found audio description format telephone-event for ID 101 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED. [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtcp:7077 IN IP4 192.168.1.107... UNSUPPORTED OR FAILED. Capabilities: us - (ulaw|g722|h264|vp8), peer - audio=(g722)/video=(nothing)/text=(nothing), combined - (g722) Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) Peer audio RTP is at port 78.26.144.10:7076 [May 27 17:34:54] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 9 from 0x7fa8980c4ad0 to 0x7fa8701d39e0 [May 27 17:34:54] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x7fa8980c4ad0 to 0x7fa8701d39e0 [May 27 17:34:54] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3851 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7fa8701d3818' Peer doesn't provide video [May 27 17:34:54] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa8702d1048' Peer doesn't provide T.140 [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10668 process_sdp: We're settling with these formats: (g722) [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10675 process_sdp: We have an owner, now see if we need to change this call [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:10681 process_sdp: Setting native formats after processing SDP. peer joint formats (g722), old nativeformats (g722) [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:6669 update_call_counter: Updating call counter for incoming call [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:11802 reqprep: Strict routing enforced for session 1783459290 set_destination: Parsing for address/port to send to [May 27 17:34:54] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.1.107' into... [May 27 17:34:54] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.1.107' and port ''. [May 27 17:34:54] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000444 [May 27 17:34:54] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000444 [May 27 17:34:54] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000444 - state 2 (In use) set_destination: set destination to 192.168.1.107:5060 [May 27 17:34:54] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000444' state '2' Transmitting (NAT) to 78.26.144.10:5060: ACK sip:linphone.iphone@192.168.1.107 SIP/2.0 Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK57c81c72;rport Max-Forwards: 70 From: "Doctor" ;tag=as0abfa1c4 To: ;tag=1085286111 Contact: Call-ID: 1783459290 CSeq: 103 ACK User-Agent: Video Medicine PBX Content-Length: 0 --- [May 27 17:34:54] DEBUG[28657][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'ACK sip:lin' onto UDP socket destined for 78.26.144.10:5060 [May 27 17:34:54] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000444' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 27 17:34:54] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:78.26.144.10:5060 ---> INVITE sip:6000333@209.239.114.51:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK254497225 From: ;tag=1085286111 To: "Doctor" ;tag=as0abfa1c4 Call-ID: 1783459290 CSeq: 22 INVITE Contact: Content-Type: application/sdp Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Max-Forwards: 70 User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Subject: Media change Content-Length: 316 v=0 o=6000444 171 2044 IN IP4 78.26.144.10 s=Talk c=IN IP4 78.26.144.10 b=AS:380 t=0 0 m=audio 7076 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 a=rtcp:7077 IN IP4 192.168.1.107 m=video 9078 RTP/AVP 102 a=rtpmap:102 H264/90000 a=fmtp:102 profile-level-id=428014 <-------------> [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 46]: INVITE sip:6000333@209.239.114.51:5060 SIP/2.0 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK254497225 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 56]: From: ;tag=1085286111 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 56]: To: "Doctor" ;tag=as0abfa1c4 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1783459290 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 15]: CSeq: 22 INVITE [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 43]: Contact: [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 29]: Content-Type: application/sdp [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 16]: Max-Forwards: 70 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 11 [ 21]: Subject: Media change [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 12 [ 19]: Content-Length: 316 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 13 [ 0]: [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 0 [ 3]: v=0 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 1 [ 38]: o=6000444 171 2044 IN IP4 78.26.144.10 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 2 [ 6]: s=Talk [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 3 [ 21]: c=IN IP4 78.26.144.10 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 4 [ 8]: b=AS:380 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 5 [ 5]: t=0 0 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 6 [ 26]: m=audio 7076 RTP/AVP 9 101 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 7 [ 20]: a=rtpmap:9 G722/8000 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 9 [ 15]: a=fmtp:101 0-11 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 10 [ 32]: a=rtcp:7077 IN IP4 192.168.1.107 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 11 [ 24]: m=video 9078 RTP/AVP 102 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 12 [ 23]: a=rtpmap:102 H264/90000 [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9605 parse_request: Body 13 [ 34]: a=fmtp:102 profile-level-id=428014 --- (13 headers 14 lines) --- [May 27 17:34:57] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1783459290 (Checking From) --From tag 1085286111 --To-tag as0abfa1c4 [May 27 17:34:57] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:27866 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE [May 27 17:34:57] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.1.107:5060' into... [May 27 17:34:57] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.1.107' and port '5060'. [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:17845 check_via: NAT detected for 192.168.1.107:5060 / 78.26.144.10:5060 Sending to 78.26.144.10:5060 (NAT) [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:24999 handle_request_invite: Initializing initreq for method INVITE - callid 1783459290 [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP o=6000444 171 2044 IN IP4 78.26.144.10... OK. [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP s=Talk... UNSUPPORTED OR FAILED. [May 27 17:34:57] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '78.26.144.10' into... [May 27 17:34:57] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '78.26.144.10' and port ''. [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP c=IN IP4 78.26.144.10... OK. [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP b=AS:380... UNSUPPORTED OR FAILED. [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. Found RTP audio format 9 [May 27 17:34:57] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 9 based on m type on 0x7fa8980c5630 Found RTP audio format 101 [May 27 17:34:57] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7fa8980c5630 Found audio description format G722 for ID 9 [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. Found audio description format telephone-event for ID 101 [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED. [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtcp:7077 IN IP4 192.168.1.107... UNSUPPORTED OR FAILED. Found RTP video format 102 [May 27 17:34:57] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 102 based on m type on 0x7fa8980c9980 Found video description format H264 for ID 102 [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (video) SDP a=rtpmap:102 H264/90000... OK. [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (video) SDP a=fmtp:102 profile-level-id=428014... OK. Capabilities: us - (ulaw|g722|h264|vp8), peer - audio=(g722)/video=(h264)/text=(nothing), combined - (g722|h264) Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [May 27 17:34:57] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa8701d3818' Peer audio RTP is at port 78.26.144.10:7076 [May 27 17:34:57] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 9 from 0x7fa8980c5630 to 0x7fa8701d39e0 [May 27 17:34:57] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x7fa8980c5630 to 0x7fa8701d39e0 [May 27 17:34:57] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3817 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7fa8701d3818' Peer video RTP is at port 78.26.144.10:9078 [May 27 17:34:57] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 102 from 0x7fa8980c9980 to 0x7fa8702ccc70 [May 27 17:34:57] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa8702d1048' Peer doesn't provide T.140 [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10668 process_sdp: We're settling with these formats: (g722|h264) [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10675 process_sdp: We have an owner, now see if we need to change this call [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:10681 process_sdp: Setting native formats after processing SDP. peer joint formats (g722|h264), old nativeformats (g722) [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:25235 handle_request_invite: Got a SIP re-invite for call 1783459290 [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:25511 handle_request_invite: SIP/6000444-000000ad: This call is UP.... <--- Transmitting (NAT) to 78.26.144.10:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.1.107:5060;branch=z9hG4bK254497225;received=78.26.144.10;rport=5060 From: ;tag=1085286111 To: "Doctor" ;tag=as0abfa1c4 Call-ID: 1783459290 CSeq: 22 INVITE Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 100' onto UDP socket destined for 78.26.144.10:5060 [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:13504 transmit_response_with_sdp: Setting framing from config on incoming call [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:13001 add_sdp: This call needs video offers, but caller probably did not offer it! [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:13054 add_sdp: ** Our capability: (g722|h264) Video flag: False Text flag: True [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:13055 add_sdp: ** Our prefcodec: (nothing) [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:13059 add_sdp: ** Our native-bridge filtered capablity: (g722) Audio is at 10642 Adding codec 100012 (g722) to SDP Adding non-codec 0x1 (telephone-event) to SDP [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:13192 add_sdp: -- Done with adding codecs to SDP [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:13390 add_sdp: Done building SDP. Settling with this capability: (g722) <--- Reliably Transmitting (NAT) to 78.26.144.10:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.1.107:5060;branch=z9hG4bK254497225;received=78.26.144.10;rport=5060 From: ;tag=1085286111 To: "Doctor" ;tag=as0abfa1c4 Call-ID: 1783459290 CSeq: 22 INVITE Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 284 v=0 o=root 1912678123 1912678126 IN IP4 89.209.100.91 s=Asterisk PBX 11.2.1 c=IN IP4 89.209.100.91 t=0 0 m=audio 7076 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 m=video 0 RTP/AVP 102 <------------> [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:4324 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #432293 [May 27 17:34:57] DEBUG[28657][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 78.26.144.10:5060 [May 27 17:34:57] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. [May 27 17:34:57] DEBUG[20574][C-00000199]: res_rtp_asterisk.c:2085 ast_rtp_update_source: Setting the marker bit due to a source update [May 27 17:34:57] DEBUG[20574][C-00000199]: rtp_engine.c:1278 remote_bridge_loop: Oooh, 'SIP/6000444-000000ad' changed end address to 78.26.144.10:7076 (format (g722|h264)) [May 27 17:34:57] DEBUG[20574][C-00000199]: rtp_engine.c:1281 remote_bridge_loop: Oooh, 'SIP/6000444-000000ad' was 78.26.144.10:7076/(format (g722|h264)) [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:32432 sip_set_rtp_peer: Sending reinvite on SIP '298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060' - It's audio soon redirected to IP 78.26.144.10:7076 [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:11802 reqprep: Strict routing enforced for session 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 set_destination: Parsing for address/port to send to [May 27 17:34:57] DEBUG[20574][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.3.93' into... [May 27 17:34:57] DEBUG[20574][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.3.93' and port ''. set_destination: set destination to 192.168.3.93:5060 [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:13054 add_sdp: ** Our capability: (g722) Video flag: True Text flag: True [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:13055 add_sdp: ** Our prefcodec: (g722) [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:13059 add_sdp: ** Our native-bridge filtered capablity: (g722) Audio is at 19716 Adding codec 100012 (g722) to SDP Adding non-codec 0x1 (telephone-event) to SDP [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:13192 add_sdp: -- Done with adding codecs to SDP [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:13390 add_sdp: Done building SDP. Settling with this capability: (g722) [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:3505 initialize_initreq: Initializing already initialized SIP dialog 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 (presumably reinvite) [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 0 [ 47]: INVITE sip:linphone.iphone@192.168.3.93 SIP/2.0 [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK6b9eebf3;rport [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 2 [ 16]: Max-Forwards: 70 [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 3 [ 59]: From: "Patient" ;tag=as4ded556c [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 4 [ 67]: To: ;tag=2071797323 [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 5 [ 42]: Contact: [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 6 [ 61]: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 7 [ 16]: CSeq: 104 INVITE [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 8 [ 30]: User-Agent: Video Medicine PBX [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 10 [ 26]: Supported: replaces, timer [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:9568 parse_request: Header 12 [ 29]: Content-Type: application/sdp Reliably Transmitting (NAT) to 89.209.100.91:5060: INVITE sip:linphone.iphone@192.168.3.93 SIP/2.0 Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK6b9eebf3;rport Max-Forwards: 70 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Contact: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 104 INVITE User-Agent: Video Medicine PBX 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: 261 v=0 o=root 1627894166 1627894168 IN IP4 78.26.144.10 s=Asterisk PBX 11.2.1 c=IN IP4 78.26.144.10 t=0 0 m=audio 7076 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 --- [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:4324 __sip_reliable_xmit: *** SIP TIMER: Initializing retransmit timer on packet: Id #432294 [May 27 17:34:57] DEBUG[20574][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 89.209.100.91:5060 <--- SIP read from UDP:89.209.100.91:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK6b9eebf3;rport=5060 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 104 INVITE User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 0 <-------------> [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 18]: SIP/2.0 100 Trying [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK6b9eebf3;rport=5060 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 59]: From: "Patient" ;tag=as4ded556c [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 67]: To: ;tag=2071797323 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 61]: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 104 INVITE [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 17]: Content-Length: 0 --- (8 headers 0 lines) --- [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 (Checking To) --From tag as4ded556c --To-tag 2071797323 [May 27 17:34:58] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:4590 __sip_semi_ack: *** SIP TIMER: Cancelling retransmission #432294 - INVITE (got response) [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:4597 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060' Request 104: Found [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:22342 handle_response_invite: SIP response 100 to RE-invite on outgoing call 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:58] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:78.26.144.10:5060 ---> ACK sip:6000333@209.239.114.51:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK1662739014 From: ;tag=1085286111 To: "Doctor" ;tag=as0abfa1c4 Call-ID: 1783459290 CSeq: 22 ACK Contact: Max-Forwards: 70 User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 0 <-------------> [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 43]: ACK sip:6000333@209.239.114.51:5060 SIP/2.0 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 66]: Via: SIP/2.0/UDP 192.168.1.107:5060;rport;branch=z9hG4bK1662739014 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 56]: From: ;tag=1085286111 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 56]: To: "Doctor" ;tag=as0abfa1c4 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1783459290 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 12]: CSeq: 22 ACK [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 43]: Contact: [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 16]: Max-Forwards: 70 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 17]: Content-Length: 0 --- (10 headers 0 lines) --- [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1783459290 (Checking From) --From tag 1085286111 --To-tag as0abfa1c4 [May 27 17:34:58] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:27866 handle_incoming: **** Received ACK (6) - Command in SIP ACK [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:4523 __sip_ack: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #432293 [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:4556 __sip_ack: Stopping retransmission on '1783459290' of Response 22: Match Found [May 27 17:34:58] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:89.209.100.91:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK6b9eebf3;rport=5060 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 104 INVITE Contact: Content-Type: application/sdp User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Content-Length: 230 v=0 o=6000333 622 2566 IN IP4 89.209.100.91 s=Talk c=IN IP4 89.209.100.91 b=AS:380 t=0 0 m=audio 7076 RTP/AVP 9 101 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11 a=rtcp:7077 IN IP4 192.168.3.93 <-------------> [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 14]: SIP/2.0 200 OK [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 70]: Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK6b9eebf3;rport=5060 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 59]: From: "Patient" ;tag=as4ded556c [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 67]: To: ;tag=2071797323 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 61]: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 104 INVITE [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 43]: Contact: [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 29]: Content-Type: application/sdp [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 19]: Content-Length: 230 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 0]: [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 0 [ 3]: v=0 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 1 [ 39]: o=6000333 622 2566 IN IP4 89.209.100.91 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 2 [ 6]: s=Talk [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 3 [ 22]: c=IN IP4 89.209.100.91 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 4 [ 8]: b=AS:380 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 5 [ 5]: t=0 0 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 6 [ 26]: m=audio 7076 RTP/AVP 9 101 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 7 [ 20]: a=rtpmap:9 G722/8000 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9568 parse_request: Body 9 [ 15]: a=fmtp:101 0-11 [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9605 parse_request: Body 10 [ 31]: a=rtcp:7077 IN IP4 192.168.3.93 --- (10 headers 11 lines) --- [May 27 17:34:58] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 (Checking To) --From tag as4ded556c --To-tag 2071797323 [May 27 17:34:58] DEBUG[28657][C-00000199]: logger.c:1324 ast_callid_threadassoc_add: CALL_ID [C-00000199] bound to thread. [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:4518 __sip_ack: Acked pending invite 104 [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:4556 __sip_ack: Stopping retransmission on '298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060' of Request 104: Match Found [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:22342 handle_response_invite: SIP response 200 to RE-invite on outgoing call 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP o=6000333 622 2566 IN IP4 89.209.100.91... OK. [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP s=Talk... UNSUPPORTED OR FAILED. [May 27 17:34:58] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '89.209.100.91' into... [May 27 17:34:58] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '89.209.100.91' and port ''. [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP c=IN IP4 89.209.100.91... OK. [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP b=AS:380... UNSUPPORTED OR FAILED. [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10000 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. Found RTP audio format 9 [May 27 17:34:58] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 9 based on m type on 0x7fa8980c4ad0 Found RTP audio format 101 [May 27 17:34:58] DEBUG[28657][C-00000199]: rtp_engine.c:557 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7fa8980c4ad0 Found audio description format G722 for ID 9 [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. Found audio description format telephone-event for ID 101 [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-11... UNSUPPORTED OR FAILED. [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10406 process_sdp: Processing media-level (audio) SDP a=rtcp:7077 IN IP4 192.168.3.93... UNSUPPORTED OR FAILED. Capabilities: us - (ulaw|g722|h264|vp8), peer - audio=(g722)/video=(nothing)/text=(nothing), combined - (g722) Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) Peer audio RTP is at port 89.209.100.91:7076 [May 27 17:34:58] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 9 from 0x7fa8980c4ad0 to 0x7fa87404ede0 [May 27 17:34:58] DEBUG[28657][C-00000199]: rtp_engine.c:515 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x7fa8980c4ad0 to 0x7fa87404ede0 [May 27 17:34:58] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3851 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7fa87404ec18' Peer doesn't provide video [May 27 17:34:58] DEBUG[28657][C-00000199]: res_rtp_asterisk.c:3896 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa8740302e8' Peer doesn't provide T.140 [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10668 process_sdp: We're settling with these formats: (g722) [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10675 process_sdp: We have an owner, now see if we need to change this call [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:10681 process_sdp: Setting native formats after processing SDP. peer joint formats (g722), old nativeformats (g722) [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:6669 update_call_counter: Updating call counter for outgoing call [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:11802 reqprep: Strict routing enforced for session 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 [May 27 17:34:58] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000333 set_destination: Parsing for address/port to send to [May 27 17:34:58] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000333 [May 27 17:34:58] DEBUG[28657][C-00000199]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.3.93' into... [May 27 17:34:58] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000333 - state 2 (In use) [May 27 17:34:58] DEBUG[28657][C-00000199]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.3.93' and port ''. [May 27 17:34:58] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000333' state '2' set_destination: set destination to 192.168.3.93:5060 Transmitting (NAT) to 89.209.100.91:5060: ACK sip:linphone.iphone@192.168.3.93 SIP/2.0 Via: SIP/2.0/UDP 209.239.114.51:5060;branch=z9hG4bK1e79e346;rport Max-Forwards: 70 From: "Patient" ;tag=as4ded556c To: ;tag=2071797323 Contact: Call-ID: 298d3297148c6b1d6082e840793be8cb@209.239.114.51:5060 CSeq: 104 ACK User-Agent: Video Medicine PBX Content-Length: 0 --- [May 27 17:34:58] DEBUG[28657][C-00000199]: chan_sip.c:3864 __sip_xmit: Trying to put 'ACK sip:lin' onto UDP socket destined for 89.209.100.91:5060 [May 27 17:34:58] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000333' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 27 17:34:58] DEBUG[28657][C-00000199]: logger.c:1346 ast_callid_threadassoc_remove: Call_ID [C-00000199] being removed from thread. <--- SIP read from UDP:89.209.100.91:1024 ---> REGISTER sip:vm.intersog.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.110:1024;rport;branch=z9hG4bK916431076 From: ;tag=1535387999 To: Call-ID: 1295208163 CSeq: 175 REGISTER Contact: Max-Forwards: 70 User-Agent: LinphoneAndroid/1.22 (eXosip2/3.6.0) Expires: 60 Content-Length: 0 <-------------> [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 36]: REGISTER sip:vm.intersog.com SIP/2.0 [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.1.110:1024;rport;branch=z9hG4bK916431076 [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 53]: From: ;tag=1535387999 [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 36]: To: [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1295208163 [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 18]: CSeq: 175 REGISTER [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 64]: Contact: [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 16]: Max-Forwards: 70 [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneAndroid/1.22 (eXosip2/3.6.0) [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 11]: Expires: 60 [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 17]: Content-Length: 0 --- (11 headers 0 lines) --- [May 27 17:35:00] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1295208163 (Checking From) --From tag 1535387999 --To-tag [May 27 17:35:00] DEBUG[28657]: acl.c:979 ast_ouraddrfor: For destination '89.209.100.91', our source address is '209.239.114.51'. [May 27 17:35:00] DEBUG[28657]: chan_sip.c:4021 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 209.239.114.51:5060 [May 27 17:35:00] DEBUG[28657]: chan_sip.c:8721 sip_alloc: Allocating new SIP dialog for 1295208163 - REGISTER (No RTP) [May 27 17:35:00] DEBUG[28657]: chan_sip.c:27866 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER [May 27 17:35:00] DEBUG[28657]: chan_sip.c:27689 handle_request_register: Initializing initreq for method REGISTER - callid 1295208163 [May 27 17:35:00] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.1.110:1024' into... [May 27 17:35:00] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.1.110' and port '1024'. [May 27 17:35:00] DEBUG[28657]: chan_sip.c:17845 check_via: NAT detected for 192.168.1.110:1024 / 89.209.100.91:1024 Sending to 89.209.100.91:1024 (NAT) [May 27 17:35:00] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com' into... [May 27 17:35:00] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port ''. [May 27 17:35:00] DEBUG[28657]: res_config_mysql.c:1617 mysql_reconnect: MySQL RealTime: Connection okay. [May 27 17:35:00] DEBUG[28657]: res_config_mysql.c:381 realtime_mysql: MySQL RealTime: Retrieve SQL: SELECT * FROM sipfriends WHERE name = '7000000229' AND host = 'dynamic' [May 27 17:35:00] DEBUG[28657]: chan_sip.c:30777 build_peer: Not an IPv4 nor IPv6 address, cannot get port. [May 27 17:35:00] DEBUG[28657]: chan_sip.c:30780 build_peer: Not an IPv4 nor IPv6 address, cannot set port. [May 27 17:35:00] DEBUG[28657]: chan_sip.c:30782 build_peer: Not an IPv4 nor IPv6 address, cannot get port. [May 27 17:35:00] DEBUG[28657]: chan_sip.c:30785 build_peer: Not an IPv4 nor IPv6 address, cannot set port. [May 27 17:35:00] DEBUG[28657]: chan_sip.c:30798 build_peer: Bah, we're expired (1369676100/0/1369676100)! [May 27 17:35:00] DEBUG[28657]: db.c:373 db_get_common: Unable to find key '7000000229' in family 'SIP/Registry' [May 27 17:35:00] DEBUG[28657]: chan_sip.c:5590 realtime_peer: -REALTIME- loading peer from database to memory. Name: 7000000229. Peer objects: 0 <--- Transmitting (NAT) to 89.209.100.91:1024 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.110:1024;branch=z9hG4bK916431076;received=89.209.100.91;rport=1024 From: ;tag=1535387999 To: ;tag=as5e628943 Call-ID: 1295208163 CSeq: 175 REGISTER Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="vm.intersog.com", nonce="4224cf55" Content-Length: 0 <------------> [May 27 17:35:00] DEBUG[28657]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 89.209.100.91:1024 Scheduling destruction of SIP dialog '1295208163' in 32000 ms (Method: REGISTER) <--- SIP read from UDP:89.209.100.91:1024 ---> REGISTER sip:vm.intersog.com SIP/2.0 Via: SIP/2.0/UDP 192.168.1.110:1024;rport;branch=z9hG4bK916431076 From: ;tag=1535387999 To: Call-ID: 1295208163 CSeq: 175 REGISTER Contact: Max-Forwards: 70 User-Agent: LinphoneAndroid/1.22 (eXosip2/3.6.0) Expires: 60 Content-Length: 0 <-------------> [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 36]: REGISTER sip:vm.intersog.com SIP/2.0 [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.1.110:1024;rport;branch=z9hG4bK916431076 [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 53]: From: ;tag=1535387999 [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 36]: To: [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 19]: Call-ID: 1295208163 [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 18]: CSeq: 175 REGISTER [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 64]: Contact: [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 16]: Max-Forwards: 70 [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneAndroid/1.22 (eXosip2/3.6.0) [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 11]: Expires: 60 [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 17]: Content-Length: 0 --- (11 headers 0 lines) --- [May 27 17:35:01] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 1295208163 (Checking From) --From tag 1535387999 --To-tag [May 27 17:35:01] DEBUG[28657]: chan_sip.c:27866 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER [May 27 17:35:01] DEBUG[28657]: chan_sip.c:27891 handle_incoming: Ignoring SIP message because of retransmit (REGISTER Seqno 175, ours 175) [May 27 17:35:01] DEBUG[28657]: chan_sip.c:27689 handle_request_register: Initializing initreq for method REGISTER - callid 1295208163 [May 27 17:35:01] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.1.110:1024' into... [May 27 17:35:01] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.1.110' and port '1024'. [May 27 17:35:01] DEBUG[28657]: chan_sip.c:17845 check_via: NAT detected for 192.168.1.110:1024 / 89.209.100.91:1024 Sending to 89.209.100.91:1024 (NAT) [May 27 17:35:01] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com' into... [May 27 17:35:01] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port ''. <--- Transmitting (NAT) to 89.209.100.91:1024 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.1.110:1024;branch=z9hG4bK916431076;received=89.209.100.91;rport=1024 From: ;tag=1535387999 To: ;tag=as5e628943 Call-ID: 1295208163 CSeq: 175 REGISTER Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="vm.intersog.com", nonce="4224cf55" Content-Length: 0 <------------> [May 27 17:35:01] DEBUG[28657]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 89.209.100.91:1024 Scheduling destruction of SIP dialog '1295208163' in 32000 ms (Method: REGISTER) <--- SIP read from UDP:89.209.100.91:5060 ---> REGISTER sip:vm.intersog.com:56382 SIP/2.0 Via: SIP/2.0/UDP 192.168.3.93:5060;rport;branch=z9hG4bK198751580 From: ;tag=830738899 To: Call-ID: 959752737 CSeq: 1 REGISTER Contact: Max-Forwards: 70 User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Expires: 600 Content-Length: 0 <-------------> [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 42]: REGISTER sip:vm.intersog.com:56382 SIP/2.0 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 64]: Via: SIP/2.0/UDP 192.168.3.93:5060;rport;branch=z9hG4bK198751580 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 55]: From: ;tag=830738899 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 39]: To: [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 18]: Call-ID: 959752737 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 1 REGISTER [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 56]: Contact: [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 16]: Max-Forwards: 70 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 12]: Expires: 600 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 17]: Content-Length: 0 --- (11 headers 0 lines) --- [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 959752737 (Checking From) --From tag 830738899 --To-tag [May 27 17:35:05] DEBUG[28657]: acl.c:979 ast_ouraddrfor: For destination '89.209.100.91', our source address is '209.239.114.51'. [May 27 17:35:05] DEBUG[28657]: chan_sip.c:4021 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 209.239.114.51:5060 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:8721 sip_alloc: Allocating new SIP dialog for 959752737 - REGISTER (No RTP) [May 27 17:35:05] DEBUG[28657]: chan_sip.c:27866 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER [May 27 17:35:05] DEBUG[28657]: chan_sip.c:27689 handle_request_register: Initializing initreq for method REGISTER - callid 959752737 [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.3.93:5060' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.3.93' and port '5060'. [May 27 17:35:05] DEBUG[28657]: chan_sip.c:17845 check_via: NAT detected for 192.168.3.93:5060 / 89.209.100.91:5060 Sending to 89.209.100.91:5060 (NAT) [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:56382' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port ''. <--- Transmitting (NAT) to 89.209.100.91:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.3.93:5060;branch=z9hG4bK198751580;received=89.209.100.91;rport=5060 From: ;tag=830738899 To: ;tag=as16a839f2 Call-ID: 959752737 CSeq: 1 REGISTER Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="vm.intersog.com", nonce="04504a9e" Content-Length: 0 <------------> [May 27 17:35:05] DEBUG[28657]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 89.209.100.91:5060 Scheduling destruction of SIP dialog '959752737' in 32000 ms (Method: REGISTER) <--- SIP read from UDP:89.209.100.91:5060 ---> REGISTER sip:vm.intersog.com:56382 SIP/2.0 Via: SIP/2.0/UDP 192.168.3.93:5060;rport;branch=z9hG4bK1501009471 From: ;tag=830738899 To: Call-ID: 959752737 CSeq: 2 REGISTER Contact: Authorization: Digest username="6000333", realm="vm.intersog.com", nonce="04504a9e", uri="sip:vm.intersog.com:56382", response="ad298518af106acf25395ed15db38405", algorithm=MD5 Max-Forwards: 70 User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Expires: 600 Content-Length: 0 <-------------> [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 42]: REGISTER sip:vm.intersog.com:56382 SIP/2.0 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 65]: Via: SIP/2.0/UDP 192.168.3.93:5060;rport;branch=z9hG4bK1501009471 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 55]: From: ;tag=830738899 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 39]: To: [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 18]: Call-ID: 959752737 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 2 REGISTER [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 56]: Contact: [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [176]: Authorization: Digest username="6000333", realm="vm.intersog.com", nonce="04504a9e", uri="sip:vm.intersog.com:56382", response="ad298518af106acf25395ed15db38405", algorithm=MD5 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 16]: Max-Forwards: 70 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 12]: Expires: 600 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 11 [ 17]: Content-Length: 0 --- (12 headers 0 lines) --- [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 959752737 (Checking From) --From tag 830738899 --To-tag [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:56382' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port '56382'. [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:56382' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port '56382'. [May 27 17:35:05] DEBUG[28657]: chan_sip.c:27866 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER [May 27 17:35:05] DEBUG[28657]: chan_sip.c:27689 handle_request_register: Initializing initreq for method REGISTER - callid 959752737 [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.3.93:5060' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.3.93' and port '5060'. [May 27 17:35:05] DEBUG[28657]: chan_sip.c:17845 check_via: NAT detected for 192.168.3.93:5060 / 89.209.100.91:5060 Sending to 89.209.100.91:5060 (NAT) [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:56382' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port ''. [May 27 17:35:05] DEBUG[28657]: chan_sip.c:15927 parse_register_contact: Store REGISTER's src-IP:port for call routing. <--- Transmitting (NAT) to 89.209.100.91:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.3.93:5060;branch=z9hG4bK1501009471;received=89.209.100.91;rport=5060 From: ;tag=830738899 To: ;tag=as16a839f2 Call-ID: 959752737 CSeq: 2 REGISTER Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Expires: 600 Contact: ;expires=600 Date: Mon, 27 May 2013 17:35:05 GMT Content-Length: 0 <------------> [May 27 17:35:05] DEBUG[28657]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 89.209.100.91:5060 Scheduling destruction of SIP dialog '959752737' in 32000 ms (Method: REGISTER) [May 27 17:35:05] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000333 [May 27 17:35:05] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000333 [May 27 17:35:05] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000333 - state 2 (In use) [May 27 17:35:05] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000333' state '2' [May 27 17:35:05] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000333' changed to state '2' (In use) but we don't care because they're not a member of any queue. <--- SIP read from UDP:89.209.100.91:5060 ---> REGISTER sip:vm.intersog.com:56382 SIP/2.0 Via: SIP/2.0/UDP 192.168.3.93:5060;rport;branch=z9hG4bK982771765 From: ;tag=830738899 To: Call-ID: 959752737 CSeq: 3 REGISTER Contact: Max-Forwards: 70 User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Expires: 600 Content-Length: 0 <-------------> [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 42]: REGISTER sip:vm.intersog.com:56382 SIP/2.0 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 64]: Via: SIP/2.0/UDP 192.168.3.93:5060;rport;branch=z9hG4bK982771765 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 55]: From: ;tag=830738899 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 39]: To: [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 18]: Call-ID: 959752737 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 3 REGISTER [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 62]: Contact: [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [ 16]: Max-Forwards: 70 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 12]: Expires: 600 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 17]: Content-Length: 0 --- (11 headers 0 lines) --- [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 959752737 (Checking From) --From tag 830738899 --To-tag [May 27 17:35:05] DEBUG[28657]: chan_sip.c:27866 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER [May 27 17:35:05] DEBUG[28657]: chan_sip.c:27689 handle_request_register: Initializing initreq for method REGISTER - callid 959752737 [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.3.93:5060' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.3.93' and port '5060'. [May 27 17:35:05] DEBUG[28657]: chan_sip.c:17845 check_via: NAT detected for 192.168.3.93:5060 / 89.209.100.91:5060 Sending to 89.209.100.91:5060 (NAT) [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:56382' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port ''. <--- Transmitting (NAT) to 89.209.100.91:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.3.93:5060;branch=z9hG4bK982771765;received=89.209.100.91;rport=5060 From: ;tag=830738899 To: ;tag=as16a839f2 Call-ID: 959752737 CSeq: 3 REGISTER Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="vm.intersog.com", nonce="03d73127" Content-Length: 0 <------------> [May 27 17:35:05] DEBUG[28657]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for 89.209.100.91:5060 Scheduling destruction of SIP dialog '959752737' in 32000 ms (Method: REGISTER) <--- SIP read from UDP:89.209.100.91:5060 ---> REGISTER sip:vm.intersog.com:56382 SIP/2.0 Via: SIP/2.0/UDP 192.168.3.93:5060;rport;branch=z9hG4bK174013936 From: ;tag=830738899 To: Call-ID: 959752737 CSeq: 4 REGISTER Contact: Authorization: Digest username="6000333", realm="vm.intersog.com", nonce="03d73127", uri="sip:vm.intersog.com:56382", response="77d047fba0d5b47d8b57bee5ad2c2ac3", algorithm=MD5 Max-Forwards: 70 User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) Expires: 600 Content-Length: 0 <-------------> [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 0 [ 42]: REGISTER sip:vm.intersog.com:56382 SIP/2.0 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 1 [ 64]: Via: SIP/2.0/UDP 192.168.3.93:5060;rport;branch=z9hG4bK174013936 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 2 [ 55]: From: ;tag=830738899 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 3 [ 39]: To: [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 4 [ 18]: Call-ID: 959752737 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 5 [ 16]: CSeq: 4 REGISTER [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 6 [ 62]: Contact: [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 7 [176]: Authorization: Digest username="6000333", realm="vm.intersog.com", nonce="03d73127", uri="sip:vm.intersog.com:56382", response="77d047fba0d5b47d8b57bee5ad2c2ac3", algorithm=MD5 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 8 [ 16]: Max-Forwards: 70 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 9 [ 48]: User-Agent: LinphoneIPhone/2.0.2 (eXosip2/3.6.0) [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 10 [ 12]: Expires: 600 [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9568 parse_request: Header 11 [ 17]: Content-Length: 0 --- (12 headers 0 lines) --- [May 27 17:35:05] DEBUG[28657]: chan_sip.c:9118 find_call: = Looking for Call ID: 959752737 (Checking From) --From tag 830738899 --To-tag [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:56382' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port '56382'. [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:56382' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port '56382'. [May 27 17:35:05] DEBUG[28657]: chan_sip.c:27866 handle_incoming: **** Received REGISTER (2) - Command in SIP REGISTER [May 27 17:35:05] DEBUG[28657]: chan_sip.c:27689 handle_request_register: Initializing initreq for method REGISTER - callid 959752737 [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '192.168.3.93:5060' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '192.168.3.93' and port '5060'. [May 27 17:35:05] DEBUG[28657]: chan_sip.c:17845 check_via: NAT detected for 192.168.3.93:5060 / 89.209.100.91:5060 Sending to 89.209.100.91:5060 (NAT) [May 27 17:35:05] DEBUG[28657]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting 'vm.intersog.com:56382' into... [May 27 17:35:05] DEBUG[28657]: netsock2.c:192 ast_sockaddr_split_hostport: ...host 'vm.intersog.com' and port ''. [May 27 17:35:05] DEBUG[28657]: chan_sip.c:15927 parse_register_contact: Store REGISTER's src-IP:port for call routing. <--- Transmitting (NAT) to 89.209.100.91:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.3.93:5060;branch=z9hG4bK174013936;received=89.209.100.91;rport=5060 From: ;tag=830738899 To: ;tag=as16a839f2 Call-ID: 959752737 CSeq: 4 REGISTER Server: Video Medicine PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Expires: 600 Contact: ;expires=600 Date: Mon, 27 May 2013 17:35:05 GMT Content-Length: 0 <------------> [May 27 17:35:05] DEBUG[28657]: chan_sip.c:3864 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 89.209.100.91:5060 Scheduling destruction of SIP dialog '959752737' in 32000 ms (Method: REGISTER) [May 27 17:35:05] DEBUG[28644]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - 6000333 [May 27 17:35:05] DEBUG[28644]: chan_sip.c:29297 sip_devicestate: Checking device state for peer 6000333 [May 27 17:35:05] DEBUG[28644]: devicestate.c:467 do_state_change: Changing state for SIP/6000333 - state 2 (In use) [May 27 17:35:05] DEBUG[28644]: devicestate.c:442 devstate_event: device 'SIP/6000333' state '2' [May 27 17:35:05] DEBUG[28686]: app_queue.c:1804 handle_statechange: Device 'SIP/6000333' changed to state '2' (In use) but we don't care because they're not a member of any queue. usloft1046*CLI>