[Sep 5 10:51:13] DEBUG[10674] pjsip: tsx0x18a5318 Sending Response msg 200/REGISTER/cseq=4459 (tdta0x1d81300) in state Trying [Sep 5 10:51:13] DEBUG[10674] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:51:13] DEBUG[10674] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:51:13] DEBUG[10674] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:51:13] DEBUG[10674] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:51:13] VERBOSE[10674] res_pjsip_logger.c: <--- Transmitting SIP response (455 bytes) to UDP:216.207.245.1:18997 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.24.74.254:5062;rport=18997;received=216.207.245.1;branch=z9hG4bK1602437911 Call-ID: 1429292974@10.24.74.254 From: "Scott Griepentrog" ;tag=1348308714 To: "Scott Griepentrog" ;tag=z9hG4bK1602437911 CSeq: 4459 REGISTER Date: Sat, 05 Sep 2015 15:51:13 GMT Contact: ;expires=299 Expires: 300 Server: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:51:13] DEBUG[10674] pjsip: tsx0x18a5318 .State changed from Trying to Completed, event=TX_MSG [Sep 5 10:51:13] DEBUG[9341] threadpool.c: Increasing threadpool Sorcery's size by 1 [Sep 5 10:51:16] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:51:16] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Completed to Terminated, event=TIMER [Sep 5 10:51:16] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:51:16] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Terminated to Destroyed, event=TIMER [Sep 5 10:51:16] DEBUG[9369] pjsip: tdta0x18d0430 ..Destroying txdata Request msg OPTIONS/cseq=3045 (tdta0x18d0430) [Sep 5 10:51:16] DEBUG[9369] pjsip: tsx0x18418b8 Transaction destroyed! [Sep 5 10:51:21] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=1 (rdata0x7faed8045968) [Sep 5 10:51:21] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP request (767 bytes) from UDP:192.151.159.122:5070 ---> INVITE sip:8090048222084974@104.236.91.141 SIP/2.0 To: 8090048222084974 From: 100;tag=dc95213d Via: SIP/2.0/UDP 192.151.159.122:5070;branch=z9hG4bK-c0abc7839a80839480ac2cb3baf5b065;rport Call-ID: c0abc7839a80839480ac2cb3baf5b065 CSeq: 1 INVITE Contact: Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, BYE User-Agent: sipcli/v1.8 Content-Type: application/sdp Content-Length: 285 v=0 o=sipcli-Session 89930363 1071492710 IN IP4 192.151.159.122 s=sipcli c=IN IP4 192.151.159.122 t=0 0 m=audio 5072 RTP/AVP 18 0 8 101 a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv [Sep 5 10:51:21] DEBUG[9369] netsock2.c: Splitting '192.151.159.122:5070' into... [Sep 5 10:51:21] DEBUG[9369] netsock2.c: ...host '192.151.159.122' and port '5070'. [Sep 5 10:51:21] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:51:21] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:51:21] DEBUG[10674] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=1 (rdata0x7faed807ef18) [Sep 5 10:51:21] DEBUG[10674] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Sep 5 10:51:21] DEBUG[10674] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 100 [Sep 5 10:51:21] DEBUG[10674] pjsip: endpoint .Response msg 401/INVITE/cseq=1 (tdta0x7faed806dcc0) created [Sep 5 10:51:21] DEBUG[10674] netsock2.c: Splitting '104.236.91.141' into... [Sep 5 10:51:21] DEBUG[10674] netsock2.c: ...host '104.236.91.141' and port ''. [Sep 5 10:51:21] DEBUG[10674] netsock2.c: Splitting '192.151.159.122' into... [Sep 5 10:51:21] DEBUG[10674] netsock2.c: ...host '192.151.159.122' and port ''. [Sep 5 10:51:21] DEBUG[10674] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:51:21] DEBUG[10674] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:51:21] DEBUG[10674] netsock2.c: Splitting '192.151.159.122:5070' into... [Sep 5 10:51:21] DEBUG[10674] netsock2.c: ...host '192.151.159.122' and port '5070'. [Sep 5 10:51:21] VERBOSE[10674] res_pjsip_logger.c: <--- Transmitting SIP response (573 bytes) to UDP:192.151.159.122:5070 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.151.159.122:5070;rport=5070;received=192.151.159.122;branch=z9hG4bK-c0abc7839a80839480ac2cb3baf5b065 Call-ID: c0abc7839a80839480ac2cb3baf5b065 From: "100" ;tag=dc95213d To: "8090048222084974" ;tag=z9hG4bK-c0abc7839a80839480ac2cb3baf5b065 CSeq: 1 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1441468281/872d55878da7b19d6f8d48d2cf203419",opaque="35d770c116a408f2",algorithm=md5,qop="auth" Server: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:51:21] DEBUG[10674] pjsip: tdta0x7faed806 .Destroying txdata Response msg 401/INVITE/cseq=1 (tdta0x7faed806dcc0) [Sep 5 10:51:26] DEBUG[9753] pjsip: endpoint Request msg OPTIONS/cseq=40711 (tdta0x18d0430) created. [Sep 5 10:51:26] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:26] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:26] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:26] DEBUG[9753] res_pjsip.c: 0x7faed80a6620: Wrapper created [Sep 5 10:51:26] DEBUG[9753] res_pjsip.c: 0x7faed80a6620: Set timer to 3000 msec [Sep 5 10:51:26] DEBUG[9753] pjsip: tsx0x18418b8 .Transaction created for Request msg OPTIONS/cseq=40711 (tdta0x18d0430) [Sep 5 10:51:26] DEBUG[9753] pjsip: tsx0x18418b8 Sending Request msg OPTIONS/cseq=40711 (tdta0x18d0430) in state Null [Sep 5 10:51:26] DEBUG[9753] pjsip: sip_resolve.c .Target '216.207.245.1:18997' type=Unspecified resolved to '216.207.245.1:18997' type=UDP (UDP transport) [Sep 5 10:51:26] DEBUG[9753] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.236.91.141:5060 [Sep 5 10:51:26] DEBUG[9753] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:51:26] DEBUG[9753] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:51:26] DEBUG[9753] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:51:26] DEBUG[9753] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:51:26] VERBOSE[9753] res_pjsip_logger.c: <--- Transmitting SIP request (500 bytes) to UDP:216.207.245.1:18997 ---> OPTIONS sip:100@216.207.245.1:18997 SIP/2.0 Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj6ae52953-6dc7-4d73-bc58-1f724263587e From: ;tag=facaf42f-fbba-4d1d-a598-be0a8ee9c19c To: Contact: Call-ID: bc305d8e-c411-4abd-a537-045c20341159 CSeq: 40711 OPTIONS Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:51:26] DEBUG[9753] pjsip: tsx0x18418b8 .State changed from Null to Calling, event=TX_MSG [Sep 5 10:51:26] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=40711 (rdata0x7faed8045968) [Sep 5 10:51:26] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP response (392 bytes) from UDP:216.207.245.1:18997 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj6ae52953-6dc7-4d73-bc58-1f724263587e From: ;tag=facaf42f-fbba-4d1d-a598-be0a8ee9c19c To: ;tag=1031486316 Call-ID: bc305d8e-c411-4abd-a537-045c20341159 CSeq: 40711 OPTIONS User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Sep 5 10:51:26] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:51:26] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:51:26] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:51:26] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:51:26] DEBUG[10674] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=40711 (rdata0x7faed80af338) [Sep 5 10:51:26] DEBUG[10674] pjsip: tsx0x18418b8 .Incoming Response msg 200/OPTIONS/cseq=40711 (rdata0x7faed80af338) in state Calling [Sep 5 10:51:26] DEBUG[10674] pjsip: tsx0x18418b8 ..State changed from Calling to Completed, event=RX_MSG [Sep 5 10:51:26] DEBUG[10674] res_pjsip.c: 0x7faed80a6620: PJSIP tsx response received [Sep 5 10:51:26] DEBUG[10674] res_pjsip.c: 0x7faed80a6620: Cancelling timer [Sep 5 10:51:26] DEBUG[10674] res_pjsip.c: 0x7faed80a6620: Timer cancelled [Sep 5 10:51:26] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:26] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:26] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:26] DEBUG[10674] res_pjsip.c: 0x7faed80a6620: Callbacks executed [Sep 5 10:51:26] DEBUG[10674] res_pjsip.c: 0x7faed80a6620: wrapper destroyed [Sep 5 10:51:31] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:51:31] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Completed to Terminated, event=TIMER [Sep 5 10:51:31] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:51:31] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Terminated to Destroyed, event=TIMER [Sep 5 10:51:31] DEBUG[9369] pjsip: tdta0x18d0430 ..Destroying txdata Request msg OPTIONS/cseq=40711 (tdta0x18d0430) [Sep 5 10:51:31] DEBUG[9369] pjsip: tsx0x18418b8 Transaction destroyed! [Sep 5 10:51:41] DEBUG[9753] pjsip: endpoint Request msg OPTIONS/cseq=42713 (tdta0x18d0430) created. [Sep 5 10:51:41] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:41] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:41] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:41] DEBUG[9753] res_pjsip.c: 0x7faed802af30: Wrapper created [Sep 5 10:51:41] DEBUG[9753] res_pjsip.c: 0x7faed802af30: Set timer to 3000 msec [Sep 5 10:51:41] DEBUG[9753] pjsip: tsx0x18418b8 .Transaction created for Request msg OPTIONS/cseq=42713 (tdta0x18d0430) [Sep 5 10:51:41] DEBUG[9753] pjsip: tsx0x18418b8 Sending Request msg OPTIONS/cseq=42713 (tdta0x18d0430) in state Null [Sep 5 10:51:41] DEBUG[9753] pjsip: sip_resolve.c .Target '216.207.245.1:18997' type=Unspecified resolved to '216.207.245.1:18997' type=UDP (UDP transport) [Sep 5 10:51:41] DEBUG[9753] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.236.91.141:5060 [Sep 5 10:51:41] DEBUG[9753] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:51:41] DEBUG[9753] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:51:41] DEBUG[9753] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:51:41] DEBUG[9753] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:51:41] VERBOSE[9753] res_pjsip_logger.c: <--- Transmitting SIP request (500 bytes) to UDP:216.207.245.1:18997 ---> OPTIONS sip:100@216.207.245.1:18997 SIP/2.0 Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj1535ee25-660c-4cdb-ad0e-31d35f1dbbad From: ;tag=0a745b4c-4c43-4feb-a904-f0487e0fd88f To: Contact: Call-ID: 235d9129-de07-463d-8a91-e748a2530ec1 CSeq: 42713 OPTIONS Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:51:41] DEBUG[9753] pjsip: tsx0x18418b8 .State changed from Null to Calling, event=TX_MSG [Sep 5 10:51:41] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=42713 (rdata0x7faed8045968) [Sep 5 10:51:41] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP response (392 bytes) from UDP:216.207.245.1:18997 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj1535ee25-660c-4cdb-ad0e-31d35f1dbbad From: ;tag=0a745b4c-4c43-4feb-a904-f0487e0fd88f To: ;tag=1494031867 Call-ID: 235d9129-de07-463d-8a91-e748a2530ec1 CSeq: 42713 OPTIONS User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Sep 5 10:51:41] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:51:41] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:51:41] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:51:41] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:51:41] DEBUG[10674] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=42713 (rdata0x7faed80af338) [Sep 5 10:51:41] DEBUG[10674] pjsip: tsx0x18418b8 .Incoming Response msg 200/OPTIONS/cseq=42713 (rdata0x7faed80af338) in state Calling [Sep 5 10:51:41] DEBUG[10674] pjsip: tsx0x18418b8 ..State changed from Calling to Completed, event=RX_MSG [Sep 5 10:51:41] DEBUG[10674] res_pjsip.c: 0x7faed802af30: PJSIP tsx response received [Sep 5 10:51:41] DEBUG[10674] res_pjsip.c: 0x7faed802af30: Cancelling timer [Sep 5 10:51:41] DEBUG[10674] res_pjsip.c: 0x7faed802af30: Timer cancelled [Sep 5 10:51:41] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:41] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:41] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:41] DEBUG[10674] res_pjsip.c: 0x7faed802af30: Callbacks executed [Sep 5 10:51:41] DEBUG[10674] res_pjsip.c: 0x7faed802af30: wrapper destroyed [Sep 5 10:51:45] DEBUG[9369] pjsip: tsx0x18a5318 Timeout timer event [Sep 5 10:51:45] DEBUG[9369] pjsip: tsx0x18a5318 .State changed from Completed to Terminated, event=TIMER [Sep 5 10:51:45] DEBUG[9369] pjsip: tsx0x18a5318 Timeout timer event [Sep 5 10:51:45] DEBUG[9369] pjsip: tsx0x18a5318 .State changed from Terminated to Destroyed, event=TIMER [Sep 5 10:51:45] DEBUG[9369] pjsip: tdta0x1d81300 ..Destroying txdata Response msg 200/REGISTER/cseq=4459 (tdta0x1d81300) [Sep 5 10:51:45] DEBUG[9369] pjsip: tsx0x18a5318 Transaction destroyed! [Sep 5 10:51:46] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:51:46] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Completed to Terminated, event=TIMER [Sep 5 10:51:46] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:51:46] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Terminated to Destroyed, event=TIMER [Sep 5 10:51:46] DEBUG[9369] pjsip: tdta0x18d0430 ..Destroying txdata Request msg OPTIONS/cseq=42713 (tdta0x18d0430) [Sep 5 10:51:46] DEBUG[9369] pjsip: tsx0x18418b8 Transaction destroyed! [Sep 5 10:51:56] DEBUG[9753] pjsip: endpoint Request msg OPTIONS/cseq=29603 (tdta0x18d0430) created. [Sep 5 10:51:56] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:56] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:56] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:56] DEBUG[9753] res_pjsip.c: 0x7faed808da90: Wrapper created [Sep 5 10:51:56] DEBUG[9753] res_pjsip.c: 0x7faed808da90: Set timer to 3000 msec [Sep 5 10:51:56] DEBUG[9753] pjsip: tsx0x18418b8 .Transaction created for Request msg OPTIONS/cseq=29603 (tdta0x18d0430) [Sep 5 10:51:56] DEBUG[9753] pjsip: tsx0x18418b8 Sending Request msg OPTIONS/cseq=29603 (tdta0x18d0430) in state Null [Sep 5 10:51:56] DEBUG[9753] pjsip: sip_resolve.c .Target '216.207.245.1:18997' type=Unspecified resolved to '216.207.245.1:18997' type=UDP (UDP transport) [Sep 5 10:51:56] DEBUG[9753] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.236.91.141:5060 [Sep 5 10:51:56] DEBUG[9753] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:51:56] DEBUG[9753] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:51:56] DEBUG[9753] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:51:56] DEBUG[9753] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:51:56] VERBOSE[9753] res_pjsip_logger.c: <--- Transmitting SIP request (500 bytes) to UDP:216.207.245.1:18997 ---> OPTIONS sip:100@216.207.245.1:18997 SIP/2.0 Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPje0bb79d9-896c-4382-96c6-e171cb784852 From: ;tag=c25eb3ac-1ec1-4e98-b2c6-a4ad78537dab To: Contact: Call-ID: 791ac703-b24f-4a09-b2ac-1e105633fba8 CSeq: 29603 OPTIONS Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:51:56] DEBUG[9753] pjsip: tsx0x18418b8 .State changed from Null to Calling, event=TX_MSG [Sep 5 10:51:57] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=29603 (rdata0x7faed8045968) [Sep 5 10:51:57] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP response (392 bytes) from UDP:216.207.245.1:18997 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPje0bb79d9-896c-4382-96c6-e171cb784852 From: ;tag=c25eb3ac-1ec1-4e98-b2c6-a4ad78537dab To: ;tag=1306059038 Call-ID: 791ac703-b24f-4a09-b2ac-1e105633fba8 CSeq: 29603 OPTIONS User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Sep 5 10:51:57] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:51:57] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:51:57] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:51:57] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:51:57] DEBUG[10674] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=29603 (rdata0x7faed80af338) [Sep 5 10:51:57] DEBUG[10674] pjsip: tsx0x18418b8 .Incoming Response msg 200/OPTIONS/cseq=29603 (rdata0x7faed80af338) in state Calling [Sep 5 10:51:57] DEBUG[10674] pjsip: tsx0x18418b8 ..State changed from Calling to Completed, event=RX_MSG [Sep 5 10:51:57] DEBUG[10674] res_pjsip.c: 0x7faed808da90: PJSIP tsx response received [Sep 5 10:51:57] DEBUG[10674] res_pjsip.c: 0x7faed808da90: Cancelling timer [Sep 5 10:51:57] DEBUG[10674] res_pjsip.c: 0x7faed808da90: Timer cancelled [Sep 5 10:51:57] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:57] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:57] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:51:57] DEBUG[10674] res_pjsip.c: 0x7faed808da90: Callbacks executed [Sep 5 10:51:57] DEBUG[10674] res_pjsip.c: 0x7faed808da90: wrapper destroyed [Sep 5 10:52:01] VERBOSE[9343] asterisk.c: Remote UNIX connection [Sep 5 10:52:01] VERBOSE[11783] asterisk.c: Remote UNIX connection disconnected [Sep 5 10:52:01] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=1 (rdata0x7faed8045968) [Sep 5 10:52:01] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP request (769 bytes) from UDP:192.151.159.122:5078 ---> INVITE sip:8100048222084974@104.236.91.141 SIP/2.0 To: 8100048222084974 From: 100;tag=70705652 Via: SIP/2.0/UDP 192.151.159.122:5078;branch=z9hG4bK-fddbdbb0473022ad5cca145b12e597b6;rport Call-ID: fddbdbb0473022ad5cca145b12e597b6 CSeq: 1 INVITE Contact: Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, BYE User-Agent: sipcli/v1.8 Content-Type: application/sdp Content-Length: 287 v=0 o=sipcli-Session 1973723973 1479188107 IN IP4 192.151.159.122 s=sipcli c=IN IP4 192.151.159.122 t=0 0 m=audio 5079 RTP/AVP 18 0 8 101 a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv [Sep 5 10:52:01] DEBUG[9369] netsock2.c: Splitting '192.151.159.122:5078' into... [Sep 5 10:52:01] DEBUG[9369] netsock2.c: ...host '192.151.159.122' and port '5078'. [Sep 5 10:52:01] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:01] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:01] DEBUG[9753] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=1 (rdata0x7faed80af338) [Sep 5 10:52:01] DEBUG[9753] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Sep 5 10:52:01] DEBUG[9753] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 100 [Sep 5 10:52:01] DEBUG[9753] pjsip: endpoint .Response msg 401/INVITE/cseq=1 (tdta0x7faed806dcc0) created [Sep 5 10:52:01] DEBUG[9753] netsock2.c: Splitting '104.236.91.141' into... [Sep 5 10:52:01] DEBUG[9753] netsock2.c: ...host '104.236.91.141' and port ''. [Sep 5 10:52:01] DEBUG[9753] netsock2.c: Splitting '192.151.159.122' into... [Sep 5 10:52:01] DEBUG[9753] netsock2.c: ...host '192.151.159.122' and port ''. [Sep 5 10:52:01] DEBUG[9753] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:01] DEBUG[9753] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:01] DEBUG[9753] netsock2.c: Splitting '192.151.159.122:5078' into... [Sep 5 10:52:01] DEBUG[9753] netsock2.c: ...host '192.151.159.122' and port '5078'. [Sep 5 10:52:01] VERBOSE[9753] res_pjsip_logger.c: <--- Transmitting SIP response (573 bytes) to UDP:192.151.159.122:5078 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.151.159.122:5078;rport=5078;received=192.151.159.122;branch=z9hG4bK-fddbdbb0473022ad5cca145b12e597b6 Call-ID: fddbdbb0473022ad5cca145b12e597b6 From: "100" ;tag=70705652 To: "8100048222084974" ;tag=z9hG4bK-fddbdbb0473022ad5cca145b12e597b6 CSeq: 1 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1441468321/1b9798e794d0192a23e05abc6b5ead23",opaque="33d682a278676f63",algorithm=md5,qop="auth" Server: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:52:01] DEBUG[9753] pjsip: tdta0x7faed806 .Destroying txdata Response msg 401/INVITE/cseq=1 (tdta0x7faed806dcc0) [Sep 5 10:52:02] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:52:02] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Completed to Terminated, event=TIMER [Sep 5 10:52:02] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:52:02] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Terminated to Destroyed, event=TIMER [Sep 5 10:52:02] DEBUG[9369] pjsip: tdta0x18d0430 ..Destroying txdata Request msg OPTIONS/cseq=29603 (tdta0x18d0430) [Sep 5 10:52:02] DEBUG[9369] pjsip: tsx0x18418b8 Transaction destroyed! [Sep 5 10:52:11] DEBUG[10674] pjsip: endpoint Request msg OPTIONS/cseq=32304 (tdta0x18d0430) created. [Sep 5 10:52:11] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:11] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:11] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:11] DEBUG[10674] res_pjsip.c: 0x7faed808da90: Wrapper created [Sep 5 10:52:11] DEBUG[10674] res_pjsip.c: 0x7faed808da90: Set timer to 3000 msec [Sep 5 10:52:11] DEBUG[10674] pjsip: tsx0x18418b8 .Transaction created for Request msg OPTIONS/cseq=32304 (tdta0x18d0430) [Sep 5 10:52:11] DEBUG[10674] pjsip: tsx0x18418b8 Sending Request msg OPTIONS/cseq=32304 (tdta0x18d0430) in state Null [Sep 5 10:52:11] DEBUG[10674] pjsip: sip_resolve.c .Target '216.207.245.1:18997' type=Unspecified resolved to '216.207.245.1:18997' type=UDP (UDP transport) [Sep 5 10:52:11] DEBUG[10674] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.236.91.141:5060 [Sep 5 10:52:11] DEBUG[10674] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:11] DEBUG[10674] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:11] DEBUG[10674] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:52:11] DEBUG[10674] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:52:11] VERBOSE[10674] res_pjsip_logger.c: <--- Transmitting SIP request (500 bytes) to UDP:216.207.245.1:18997 ---> OPTIONS sip:100@216.207.245.1:18997 SIP/2.0 Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj3826adaa-23f2-4b4a-b580-0152f3610ea0 From: ;tag=83c724b3-8a2f-4120-8af7-ca7c69902771 To: Contact: Call-ID: e6afff18-fecb-4e24-ab48-6f81a05a03b4 CSeq: 32304 OPTIONS Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:52:11] DEBUG[10674] pjsip: tsx0x18418b8 .State changed from Null to Calling, event=TX_MSG [Sep 5 10:52:11] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=32304 (rdata0x7faed8045968) [Sep 5 10:52:11] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP response (392 bytes) from UDP:216.207.245.1:18997 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj3826adaa-23f2-4b4a-b580-0152f3610ea0 From: ;tag=83c724b3-8a2f-4120-8af7-ca7c69902771 To: ;tag=1439607370 Call-ID: e6afff18-fecb-4e24-ab48-6f81a05a03b4 CSeq: 32304 OPTIONS User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Sep 5 10:52:11] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:52:11] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:52:11] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:11] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:11] DEBUG[9753] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=32304 (rdata0x7faed80af338) [Sep 5 10:52:11] DEBUG[9753] pjsip: tsx0x18418b8 .Incoming Response msg 200/OPTIONS/cseq=32304 (rdata0x7faed80af338) in state Calling [Sep 5 10:52:11] DEBUG[9753] pjsip: tsx0x18418b8 ..State changed from Calling to Completed, event=RX_MSG [Sep 5 10:52:11] DEBUG[9753] res_pjsip.c: 0x7faed808da90: PJSIP tsx response received [Sep 5 10:52:11] DEBUG[9753] res_pjsip.c: 0x7faed808da90: Cancelling timer [Sep 5 10:52:11] DEBUG[9753] res_pjsip.c: 0x7faed808da90: Timer cancelled [Sep 5 10:52:11] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:11] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:11] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:11] DEBUG[9753] res_pjsip.c: 0x7faed808da90: Callbacks executed [Sep 5 10:52:11] DEBUG[9753] res_pjsip.c: 0x7faed808da90: wrapper destroyed [Sep 5 10:52:13] DEBUG[11763] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 5 10:52:13] DEBUG[9341] threadpool.c: Destroying worker thread 214 [Sep 5 10:52:16] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:52:16] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Completed to Terminated, event=TIMER [Sep 5 10:52:16] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:52:16] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Terminated to Destroyed, event=TIMER [Sep 5 10:52:16] DEBUG[9369] pjsip: tdta0x18d0430 ..Destroying txdata Request msg OPTIONS/cseq=32304 (tdta0x18d0430) [Sep 5 10:52:16] DEBUG[9369] pjsip: tsx0x18418b8 Transaction destroyed! [Sep 5 10:52:26] DEBUG[10674] pjsip: endpoint Request msg OPTIONS/cseq=54950 (tdta0x18d0430) created. [Sep 5 10:52:26] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:26] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:26] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:26] DEBUG[10674] res_pjsip.c: 0x7faed80a6620: Wrapper created [Sep 5 10:52:26] DEBUG[10674] res_pjsip.c: 0x7faed80a6620: Set timer to 3000 msec [Sep 5 10:52:26] DEBUG[10674] pjsip: tsx0x18418b8 .Transaction created for Request msg OPTIONS/cseq=54950 (tdta0x18d0430) [Sep 5 10:52:26] DEBUG[10674] pjsip: tsx0x18418b8 Sending Request msg OPTIONS/cseq=54950 (tdta0x18d0430) in state Null [Sep 5 10:52:26] DEBUG[10674] pjsip: sip_resolve.c .Target '216.207.245.1:18997' type=Unspecified resolved to '216.207.245.1:18997' type=UDP (UDP transport) [Sep 5 10:52:26] DEBUG[10674] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.236.91.141:5060 [Sep 5 10:52:26] DEBUG[10674] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:26] DEBUG[10674] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:26] DEBUG[10674] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:52:26] DEBUG[10674] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:52:26] VERBOSE[10674] res_pjsip_logger.c: <--- Transmitting SIP request (500 bytes) to UDP:216.207.245.1:18997 ---> OPTIONS sip:100@216.207.245.1:18997 SIP/2.0 Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj60eebd4b-e68b-4d37-8b74-fe920ffb422f From: ;tag=046d2a26-5f54-48d6-8dd3-195a4c3ac2f2 To: Contact: Call-ID: 681ec6bc-0809-46e6-9b87-029db95ddd87 CSeq: 54950 OPTIONS Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:52:26] DEBUG[10674] pjsip: tsx0x18418b8 .State changed from Null to Calling, event=TX_MSG [Sep 5 10:52:26] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=54950 (rdata0x7faed8045968) [Sep 5 10:52:26] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP response (391 bytes) from UDP:216.207.245.1:18997 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj60eebd4b-e68b-4d37-8b74-fe920ffb422f From: ;tag=046d2a26-5f54-48d6-8dd3-195a4c3ac2f2 To: ;tag=805246716 Call-ID: 681ec6bc-0809-46e6-9b87-029db95ddd87 CSeq: 54950 OPTIONS User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Sep 5 10:52:26] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:52:26] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:52:26] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:26] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:26] DEBUG[9753] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=54950 (rdata0x7faed80af338) [Sep 5 10:52:26] DEBUG[9753] pjsip: tsx0x18418b8 .Incoming Response msg 200/OPTIONS/cseq=54950 (rdata0x7faed80af338) in state Calling [Sep 5 10:52:26] DEBUG[9753] pjsip: tsx0x18418b8 ..State changed from Calling to Completed, event=RX_MSG [Sep 5 10:52:26] DEBUG[9753] res_pjsip.c: 0x7faed80a6620: PJSIP tsx response received [Sep 5 10:52:26] DEBUG[9753] res_pjsip.c: 0x7faed80a6620: Cancelling timer [Sep 5 10:52:26] DEBUG[9753] res_pjsip.c: 0x7faed80a6620: Timer cancelled [Sep 5 10:52:26] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:26] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:26] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:26] DEBUG[9753] res_pjsip.c: 0x7faed80a6620: Callbacks executed [Sep 5 10:52:26] DEBUG[9753] res_pjsip.c: 0x7faed80a6620: wrapper destroyed [Sep 5 10:52:31] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:52:31] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Completed to Terminated, event=TIMER [Sep 5 10:52:31] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:52:31] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Terminated to Destroyed, event=TIMER [Sep 5 10:52:31] DEBUG[9369] pjsip: tdta0x18d0430 ..Destroying txdata Request msg OPTIONS/cseq=54950 (tdta0x18d0430) [Sep 5 10:52:31] DEBUG[9369] pjsip: tsx0x18418b8 Transaction destroyed! [Sep 5 10:52:41] DEBUG[10674] pjsip: endpoint Request msg OPTIONS/cseq=32669 (tdta0x18d0430) created. [Sep 5 10:52:41] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:41] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:41] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:41] DEBUG[10674] res_pjsip.c: 0x7faed8082320: Wrapper created [Sep 5 10:52:41] DEBUG[10674] res_pjsip.c: 0x7faed8082320: Set timer to 3000 msec [Sep 5 10:52:41] DEBUG[10674] pjsip: tsx0x18418b8 .Transaction created for Request msg OPTIONS/cseq=32669 (tdta0x18d0430) [Sep 5 10:52:41] DEBUG[10674] pjsip: tsx0x18418b8 Sending Request msg OPTIONS/cseq=32669 (tdta0x18d0430) in state Null [Sep 5 10:52:41] DEBUG[10674] pjsip: sip_resolve.c .Target '216.207.245.1:18997' type=Unspecified resolved to '216.207.245.1:18997' type=UDP (UDP transport) [Sep 5 10:52:41] DEBUG[10674] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.236.91.141:5060 [Sep 5 10:52:41] DEBUG[10674] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:41] DEBUG[10674] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:41] DEBUG[10674] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:52:41] DEBUG[10674] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:52:41] VERBOSE[10674] res_pjsip_logger.c: <--- Transmitting SIP request (500 bytes) to UDP:216.207.245.1:18997 ---> OPTIONS sip:100@216.207.245.1:18997 SIP/2.0 Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj165f250e-b9c1-4085-aaaf-0034d7c8d4d8 From: ;tag=ad326a4d-3715-4e07-9385-94a5ceb7aee8 To: Contact: Call-ID: ddd0e00f-d9a7-4826-b8be-4701eda46448 CSeq: 32669 OPTIONS Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:52:41] DEBUG[10674] pjsip: tsx0x18418b8 .State changed from Null to Calling, event=TX_MSG [Sep 5 10:52:42] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=32669 (rdata0x7faed8045968) [Sep 5 10:52:42] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP response (391 bytes) from UDP:216.207.245.1:18997 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj165f250e-b9c1-4085-aaaf-0034d7c8d4d8 From: ;tag=ad326a4d-3715-4e07-9385-94a5ceb7aee8 To: ;tag=217620068 Call-ID: ddd0e00f-d9a7-4826-b8be-4701eda46448 CSeq: 32669 OPTIONS User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Sep 5 10:52:42] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:52:42] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:52:42] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:42] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:42] DEBUG[9753] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=32669 (rdata0x7faed80af338) [Sep 5 10:52:42] DEBUG[9753] pjsip: tsx0x18418b8 .Incoming Response msg 200/OPTIONS/cseq=32669 (rdata0x7faed80af338) in state Calling [Sep 5 10:52:42] DEBUG[9753] pjsip: tsx0x18418b8 ..State changed from Calling to Completed, event=RX_MSG [Sep 5 10:52:42] DEBUG[9753] res_pjsip.c: 0x7faed8082320: PJSIP tsx response received [Sep 5 10:52:42] DEBUG[9753] res_pjsip.c: 0x7faed8082320: Cancelling timer [Sep 5 10:52:42] DEBUG[9753] res_pjsip.c: 0x7faed8082320: Timer cancelled [Sep 5 10:52:42] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:42] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:42] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:42] DEBUG[9753] res_pjsip.c: 0x7faed8082320: Callbacks executed [Sep 5 10:52:42] DEBUG[9753] res_pjsip.c: 0x7faed8082320: wrapper destroyed [Sep 5 10:52:42] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=1 (rdata0x7faed8045968) [Sep 5 10:52:42] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP request (768 bytes) from UDP:192.151.159.122:5074 ---> INVITE sip:8110048222084974@104.236.91.141 SIP/2.0 To: 8110048222084974 From: 100;tag=aab1570f Via: SIP/2.0/UDP 192.151.159.122:5074;branch=z9hG4bK-b5082cfed3c94b87d60b89476c1096e3;rport Call-ID: b5082cfed3c94b87d60b89476c1096e3 CSeq: 1 INVITE Contact: Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, BYE User-Agent: sipcli/v1.8 Content-Type: application/sdp Content-Length: 286 v=0 o=sipcli-Session 288465688 1087965728 IN IP4 192.151.159.122 s=sipcli c=IN IP4 192.151.159.122 t=0 0 m=audio 5075 RTP/AVP 18 0 8 101 a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv [Sep 5 10:52:42] DEBUG[9369] netsock2.c: Splitting '192.151.159.122:5074' into... [Sep 5 10:52:42] DEBUG[9369] netsock2.c: ...host '192.151.159.122' and port '5074'. [Sep 5 10:52:42] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:42] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:42] DEBUG[10674] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=1 (rdata0x7faed80af338) [Sep 5 10:52:42] DEBUG[10674] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Sep 5 10:52:42] DEBUG[10674] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 100 [Sep 5 10:52:42] DEBUG[10674] pjsip: endpoint .Response msg 401/INVITE/cseq=1 (tdta0x7faed806dcc0) created [Sep 5 10:52:42] DEBUG[10674] netsock2.c: Splitting '104.236.91.141' into... [Sep 5 10:52:42] DEBUG[10674] netsock2.c: ...host '104.236.91.141' and port ''. [Sep 5 10:52:42] DEBUG[10674] netsock2.c: Splitting '192.151.159.122' into... [Sep 5 10:52:42] DEBUG[10674] netsock2.c: ...host '192.151.159.122' and port ''. [Sep 5 10:52:42] DEBUG[10674] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:42] DEBUG[10674] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:42] DEBUG[10674] netsock2.c: Splitting '192.151.159.122:5074' into... [Sep 5 10:52:42] DEBUG[10674] netsock2.c: ...host '192.151.159.122' and port '5074'. [Sep 5 10:52:42] VERBOSE[10674] res_pjsip_logger.c: <--- Transmitting SIP response (573 bytes) to UDP:192.151.159.122:5074 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.151.159.122:5074;rport=5074;received=192.151.159.122;branch=z9hG4bK-b5082cfed3c94b87d60b89476c1096e3 Call-ID: b5082cfed3c94b87d60b89476c1096e3 From: "100" ;tag=aab1570f To: "8110048222084974" ;tag=z9hG4bK-b5082cfed3c94b87d60b89476c1096e3 CSeq: 1 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1441468362/1cfe7285353c2673aa41076ef65768ea",opaque="7c16b4633659a457",algorithm=md5,qop="auth" Server: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:52:42] DEBUG[10674] pjsip: tdta0x7faed806 .Destroying txdata Response msg 401/INVITE/cseq=1 (tdta0x7faed806dcc0) [Sep 5 10:52:47] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:52:47] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Completed to Terminated, event=TIMER [Sep 5 10:52:47] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:52:47] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Terminated to Destroyed, event=TIMER [Sep 5 10:52:47] DEBUG[9369] pjsip: tdta0x18d0430 ..Destroying txdata Request msg OPTIONS/cseq=32669 (tdta0x18d0430) [Sep 5 10:52:47] DEBUG[9369] pjsip: tsx0x18418b8 Transaction destroyed! [Sep 5 10:52:56] DEBUG[9753] pjsip: endpoint Request msg OPTIONS/cseq=625 (tdta0x18d0430) created. [Sep 5 10:52:56] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:56] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:56] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:56] DEBUG[9753] res_pjsip.c: 0x7faed8082320: Wrapper created [Sep 5 10:52:56] DEBUG[9753] res_pjsip.c: 0x7faed8082320: Set timer to 3000 msec [Sep 5 10:52:56] DEBUG[9753] pjsip: tsx0x18418b8 .Transaction created for Request msg OPTIONS/cseq=625 (tdta0x18d0430) [Sep 5 10:52:56] DEBUG[9753] pjsip: tsx0x18418b8 Sending Request msg OPTIONS/cseq=625 (tdta0x18d0430) in state Null [Sep 5 10:52:56] DEBUG[9753] pjsip: sip_resolve.c .Target '216.207.245.1:18997' type=Unspecified resolved to '216.207.245.1:18997' type=UDP (UDP transport) [Sep 5 10:52:56] DEBUG[9753] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.236.91.141:5060 [Sep 5 10:52:56] DEBUG[9753] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:56] DEBUG[9753] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:56] DEBUG[9753] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:52:56] DEBUG[9753] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:52:56] VERBOSE[9753] res_pjsip_logger.c: <--- Transmitting SIP request (498 bytes) to UDP:216.207.245.1:18997 ---> OPTIONS sip:100@216.207.245.1:18997 SIP/2.0 Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPjd9ff6b05-17b1-4772-a4ce-75f576630e7d From: ;tag=ef939566-90d8-4479-b36f-ead36c633c85 To: Contact: Call-ID: 8a8fc8ba-43a6-4c0d-a04e-1b925838ab33 CSeq: 625 OPTIONS Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:52:56] DEBUG[9753] pjsip: tsx0x18418b8 .State changed from Null to Calling, event=TX_MSG [Sep 5 10:52:56] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=625 (rdata0x7faed8045968) [Sep 5 10:52:56] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP response (389 bytes) from UDP:216.207.245.1:18997 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPjd9ff6b05-17b1-4772-a4ce-75f576630e7d From: ;tag=ef939566-90d8-4479-b36f-ead36c633c85 To: ;tag=901416262 Call-ID: 8a8fc8ba-43a6-4c0d-a04e-1b925838ab33 CSeq: 625 OPTIONS User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Sep 5 10:52:56] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:52:56] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:52:56] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:52:56] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:52:56] DEBUG[10674] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=625 (rdata0x7faed80af338) [Sep 5 10:52:56] DEBUG[10674] pjsip: tsx0x18418b8 .Incoming Response msg 200/OPTIONS/cseq=625 (rdata0x7faed80af338) in state Calling [Sep 5 10:52:56] DEBUG[10674] pjsip: tsx0x18418b8 ..State changed from Calling to Completed, event=RX_MSG [Sep 5 10:52:56] DEBUG[10674] res_pjsip.c: 0x7faed8082320: PJSIP tsx response received [Sep 5 10:52:56] DEBUG[10674] res_pjsip.c: 0x7faed8082320: Cancelling timer [Sep 5 10:52:56] DEBUG[10674] res_pjsip.c: 0x7faed8082320: Timer cancelled [Sep 5 10:52:56] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:56] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:56] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:52:56] DEBUG[10674] res_pjsip.c: 0x7faed8082320: Callbacks executed [Sep 5 10:52:56] DEBUG[10674] res_pjsip.c: 0x7faed8082320: wrapper destroyed [Sep 5 10:53:01] VERBOSE[9343] asterisk.c: Remote UNIX connection [Sep 5 10:53:01] VERBOSE[11810] asterisk.c: Remote UNIX connection disconnected [Sep 5 10:53:01] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:53:01] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Completed to Terminated, event=TIMER [Sep 5 10:53:01] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:53:01] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Terminated to Destroyed, event=TIMER [Sep 5 10:53:01] DEBUG[9369] pjsip: tdta0x18d0430 ..Destroying txdata Request msg OPTIONS/cseq=625 (tdta0x18d0430) [Sep 5 10:53:01] DEBUG[9369] pjsip: tsx0x18418b8 Transaction destroyed! [Sep 5 10:53:11] DEBUG[9753] pjsip: endpoint Request msg OPTIONS/cseq=64986 (tdta0x18d0430) created. [Sep 5 10:53:11] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:11] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:11] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:11] DEBUG[9753] res_pjsip.c: 0x7faed808da90: Wrapper created [Sep 5 10:53:11] DEBUG[9753] res_pjsip.c: 0x7faed808da90: Set timer to 3000 msec [Sep 5 10:53:11] DEBUG[9753] pjsip: tsx0x18418b8 .Transaction created for Request msg OPTIONS/cseq=64986 (tdta0x18d0430) [Sep 5 10:53:11] DEBUG[9753] pjsip: tsx0x18418b8 Sending Request msg OPTIONS/cseq=64986 (tdta0x18d0430) in state Null [Sep 5 10:53:11] DEBUG[9753] pjsip: sip_resolve.c .Target '216.207.245.1:18997' type=Unspecified resolved to '216.207.245.1:18997' type=UDP (UDP transport) [Sep 5 10:53:11] DEBUG[9753] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.236.91.141:5060 [Sep 5 10:53:11] DEBUG[9753] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:11] DEBUG[9753] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:11] DEBUG[9753] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:53:11] DEBUG[9753] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:53:11] VERBOSE[9753] res_pjsip_logger.c: <--- Transmitting SIP request (500 bytes) to UDP:216.207.245.1:18997 ---> OPTIONS sip:100@216.207.245.1:18997 SIP/2.0 Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj9d8170ca-e3d2-495a-a536-538a4d09bb31 From: ;tag=40987553-2001-41df-9062-bb31df88ab4b To: Contact: Call-ID: 6770d612-f85c-4b3d-b9ca-efe2af113c97 CSeq: 64986 OPTIONS Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:53:11] DEBUG[9753] pjsip: tsx0x18418b8 .State changed from Null to Calling, event=TX_MSG [Sep 5 10:53:11] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=64986 (rdata0x7faed8045968) [Sep 5 10:53:11] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP response (391 bytes) from UDP:216.207.245.1:18997 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj9d8170ca-e3d2-495a-a536-538a4d09bb31 From: ;tag=40987553-2001-41df-9062-bb31df88ab4b To: ;tag=997561441 Call-ID: 6770d612-f85c-4b3d-b9ca-efe2af113c97 CSeq: 64986 OPTIONS User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Sep 5 10:53:11] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:53:11] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:53:11] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:11] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:11] DEBUG[10674] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=64986 (rdata0x7faed80af338) [Sep 5 10:53:11] DEBUG[10674] pjsip: tsx0x18418b8 .Incoming Response msg 200/OPTIONS/cseq=64986 (rdata0x7faed80af338) in state Calling [Sep 5 10:53:11] DEBUG[10674] pjsip: tsx0x18418b8 ..State changed from Calling to Completed, event=RX_MSG [Sep 5 10:53:11] DEBUG[10674] res_pjsip.c: 0x7faed808da90: PJSIP tsx response received [Sep 5 10:53:11] DEBUG[10674] res_pjsip.c: 0x7faed808da90: Cancelling timer [Sep 5 10:53:11] DEBUG[10674] res_pjsip.c: 0x7faed808da90: Timer cancelled [Sep 5 10:53:11] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:11] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:11] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:11] DEBUG[10674] res_pjsip.c: 0x7faed808da90: Callbacks executed [Sep 5 10:53:11] DEBUG[10674] res_pjsip.c: 0x7faed808da90: wrapper destroyed [Sep 5 10:53:16] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:53:16] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Completed to Terminated, event=TIMER [Sep 5 10:53:16] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:53:16] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Terminated to Destroyed, event=TIMER [Sep 5 10:53:16] DEBUG[9369] pjsip: tdta0x18d0430 ..Destroying txdata Request msg OPTIONS/cseq=64986 (tdta0x18d0430) [Sep 5 10:53:16] DEBUG[9369] pjsip: tsx0x18418b8 Transaction destroyed! [Sep 5 10:53:22] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=1 (rdata0x7faed8045968) [Sep 5 10:53:22] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP request (769 bytes) from UDP:192.151.159.122:5071 ---> INVITE sip:8120048222084974@104.236.91.141 SIP/2.0 To: 8120048222084974 From: 100;tag=029f3b02 Via: SIP/2.0/UDP 192.151.159.122:5071;branch=z9hG4bK-041a879bf3c3e7939089a99374353707;rport Call-ID: 041a879bf3c3e7939089a99374353707 CSeq: 1 INVITE Contact: Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, BYE User-Agent: sipcli/v1.8 Content-Type: application/sdp Content-Length: 287 v=0 o=sipcli-Session 1558740574 1358231730 IN IP4 192.151.159.122 s=sipcli c=IN IP4 192.151.159.122 t=0 0 m=audio 5073 RTP/AVP 18 0 8 101 a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv [Sep 5 10:53:22] DEBUG[9369] netsock2.c: Splitting '192.151.159.122:5071' into... [Sep 5 10:53:22] DEBUG[9369] netsock2.c: ...host '192.151.159.122' and port '5071'. [Sep 5 10:53:22] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:22] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:22] DEBUG[9753] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=1 (rdata0x7faed807ef18) [Sep 5 10:53:22] DEBUG[9753] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Sep 5 10:53:22] DEBUG[9753] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 100 [Sep 5 10:53:22] DEBUG[9753] pjsip: endpoint .Response msg 401/INVITE/cseq=1 (tdta0x1d81300) created [Sep 5 10:53:22] DEBUG[9753] netsock2.c: Splitting '104.236.91.141' into... [Sep 5 10:53:22] DEBUG[9753] netsock2.c: ...host '104.236.91.141' and port ''. [Sep 5 10:53:22] DEBUG[9753] netsock2.c: Splitting '192.151.159.122' into... [Sep 5 10:53:22] DEBUG[9753] netsock2.c: ...host '192.151.159.122' and port ''. [Sep 5 10:53:22] DEBUG[9753] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:22] DEBUG[9753] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:22] DEBUG[9753] netsock2.c: Splitting '192.151.159.122:5071' into... [Sep 5 10:53:22] DEBUG[9753] netsock2.c: ...host '192.151.159.122' and port '5071'. [Sep 5 10:53:22] VERBOSE[9753] res_pjsip_logger.c: <--- Transmitting SIP response (573 bytes) to UDP:192.151.159.122:5071 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.151.159.122:5071;rport=5071;received=192.151.159.122;branch=z9hG4bK-041a879bf3c3e7939089a99374353707 Call-ID: 041a879bf3c3e7939089a99374353707 From: "100" ;tag=029f3b02 To: "8120048222084974" ;tag=z9hG4bK-041a879bf3c3e7939089a99374353707 CSeq: 1 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1441468402/3cee470564ec55461fe8ad8aa37f3bfc",opaque="35ba1ba904f258c7",algorithm=md5,qop="auth" Server: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:53:22] DEBUG[9753] pjsip: tdta0x1d81300 .Destroying txdata Response msg 401/INVITE/cseq=1 (tdta0x1d81300) [Sep 5 10:53:26] DEBUG[10674] pjsip: endpoint Request msg OPTIONS/cseq=35935 (tdta0x18d0430) created. [Sep 5 10:53:26] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:26] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:26] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:26] DEBUG[10674] res_pjsip.c: 0x7faed808da90: Wrapper created [Sep 5 10:53:26] DEBUG[10674] res_pjsip.c: 0x7faed808da90: Set timer to 3000 msec [Sep 5 10:53:26] DEBUG[10674] pjsip: tsx0x18418b8 .Transaction created for Request msg OPTIONS/cseq=35935 (tdta0x18d0430) [Sep 5 10:53:26] DEBUG[10674] pjsip: tsx0x18418b8 Sending Request msg OPTIONS/cseq=35935 (tdta0x18d0430) in state Null [Sep 5 10:53:26] DEBUG[10674] pjsip: sip_resolve.c .Target '216.207.245.1:18997' type=Unspecified resolved to '216.207.245.1:18997' type=UDP (UDP transport) [Sep 5 10:53:26] DEBUG[10674] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.236.91.141:5060 [Sep 5 10:53:26] DEBUG[10674] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:26] DEBUG[10674] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:26] DEBUG[10674] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:53:26] DEBUG[10674] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:53:26] VERBOSE[10674] res_pjsip_logger.c: <--- Transmitting SIP request (500 bytes) to UDP:216.207.245.1:18997 ---> OPTIONS sip:100@216.207.245.1:18997 SIP/2.0 Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj7e424bfe-a7f2-42e4-b92f-1c1246672a94 From: ;tag=cef458fd-3f3b-4216-8f71-55946007d4d4 To: Contact: Call-ID: dc2cc15b-ddcc-4257-af24-e41d73c8a1de CSeq: 35935 OPTIONS Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:53:26] DEBUG[10674] pjsip: tsx0x18418b8 .State changed from Null to Calling, event=TX_MSG [Sep 5 10:53:26] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=35935 (rdata0x7faed8045968) [Sep 5 10:53:26] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP response (390 bytes) from UDP:216.207.245.1:18997 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj7e424bfe-a7f2-42e4-b92f-1c1246672a94 From: ;tag=cef458fd-3f3b-4216-8f71-55946007d4d4 To: ;tag=99305897 Call-ID: dc2cc15b-ddcc-4257-af24-e41d73c8a1de CSeq: 35935 OPTIONS User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Sep 5 10:53:26] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:53:26] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:53:26] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:26] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:26] DEBUG[9753] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=35935 (rdata0x7faed80af338) [Sep 5 10:53:26] DEBUG[9753] pjsip: tsx0x18418b8 .Incoming Response msg 200/OPTIONS/cseq=35935 (rdata0x7faed80af338) in state Calling [Sep 5 10:53:26] DEBUG[9753] pjsip: tsx0x18418b8 ..State changed from Calling to Completed, event=RX_MSG [Sep 5 10:53:26] DEBUG[9753] res_pjsip.c: 0x7faed808da90: PJSIP tsx response received [Sep 5 10:53:26] DEBUG[9753] res_pjsip.c: 0x7faed808da90: Cancelling timer [Sep 5 10:53:26] DEBUG[9753] res_pjsip.c: 0x7faed808da90: Timer cancelled [Sep 5 10:53:26] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:26] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:26] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:26] DEBUG[9753] res_pjsip.c: 0x7faed808da90: Callbacks executed [Sep 5 10:53:26] DEBUG[9753] res_pjsip.c: 0x7faed808da90: wrapper destroyed [Sep 5 10:53:31] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:53:31] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Completed to Terminated, event=TIMER [Sep 5 10:53:31] DEBUG[9369] pjsip: tsx0x18418b8 Timeout timer event [Sep 5 10:53:31] DEBUG[9369] pjsip: tsx0x18418b8 .State changed from Terminated to Destroyed, event=TIMER [Sep 5 10:53:31] DEBUG[9369] pjsip: tdta0x18d0430 ..Destroying txdata Request msg OPTIONS/cseq=35935 (tdta0x18d0430) [Sep 5 10:53:31] DEBUG[9369] pjsip: tsx0x18418b8 Transaction destroyed! [Sep 5 10:53:41] DEBUG[10674] pjsip: endpoint Request msg OPTIONS/cseq=17253 (tdta0x18d0430) created. [Sep 5 10:53:41] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:41] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:41] DEBUG[10674] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:41] DEBUG[10674] res_pjsip.c: 0x7faed80a6530: Wrapper created [Sep 5 10:53:41] DEBUG[10674] res_pjsip.c: 0x7faed80a6530: Set timer to 3000 msec [Sep 5 10:53:41] DEBUG[10674] pjsip: tsx0x18418b8 .Transaction created for Request msg OPTIONS/cseq=17253 (tdta0x18d0430) [Sep 5 10:53:41] DEBUG[10674] pjsip: tsx0x18418b8 Sending Request msg OPTIONS/cseq=17253 (tdta0x18d0430) in state Null [Sep 5 10:53:41] DEBUG[10674] pjsip: sip_resolve.c .Target '216.207.245.1:18997' type=Unspecified resolved to '216.207.245.1:18997' type=UDP (UDP transport) [Sep 5 10:53:41] DEBUG[10674] res_pjsip_multihomed.c: Re-wrote Contact URI host/port to 104.236.91.141:5060 [Sep 5 10:53:41] DEBUG[10674] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:41] DEBUG[10674] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:41] DEBUG[10674] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:53:41] DEBUG[10674] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:53:41] VERBOSE[10674] res_pjsip_logger.c: <--- Transmitting SIP request (500 bytes) to UDP:216.207.245.1:18997 ---> OPTIONS sip:100@216.207.245.1:18997 SIP/2.0 Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj51213b74-3cdc-4ce3-905f-3462d1e79056 From: ;tag=6434021a-8f0e-4a71-91a3-96ad2049edb3 To: Contact: Call-ID: ff07044b-3937-49ef-80f3-9b8a27042d4b CSeq: 17253 OPTIONS Max-Forwards: 70 User-Agent: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:53:41] DEBUG[10674] pjsip: tsx0x18418b8 .State changed from Null to Calling, event=TX_MSG [Sep 5 10:53:41] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Response msg 200/OPTIONS/cseq=17253 (rdata0x7faed8045968) [Sep 5 10:53:41] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP response (392 bytes) from UDP:216.207.245.1:18997 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 104.236.91.141:5060;rport;branch=z9hG4bKPj51213b74-3cdc-4ce3-905f-3462d1e79056 From: ;tag=6434021a-8f0e-4a71-91a3-96ad2049edb3 To: ;tag=2122337468 Call-ID: ff07044b-3937-49ef-80f3-9b8a27042d4b CSeq: 17253 OPTIONS User-Agent: Yealink SIP-T28P 2.61.0.80 Content-Length: 0 [Sep 5 10:53:41] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:53:41] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:53:41] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:41] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:41] DEBUG[9753] pjsip: sip_endpoint.c Distributing rdata to modules: Response msg 200/OPTIONS/cseq=17253 (rdata0x7faed80af338) [Sep 5 10:53:41] DEBUG[9753] pjsip: tsx0x18418b8 .Incoming Response msg 200/OPTIONS/cseq=17253 (rdata0x7faed80af338) in state Calling [Sep 5 10:53:41] DEBUG[9753] pjsip: tsx0x18418b8 ..State changed from Calling to Completed, event=RX_MSG [Sep 5 10:53:41] DEBUG[9753] res_pjsip.c: 0x7faed80a6530: PJSIP tsx response received [Sep 5 10:53:41] DEBUG[9753] res_pjsip.c: 0x7faed80a6530: Cancelling timer [Sep 5 10:53:41] DEBUG[9753] res_pjsip.c: 0x7faed80a6530: Timer cancelled [Sep 5 10:53:41] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:41] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:41] DEBUG[9753] config.c: extract int from [0] in [-2147483648, 2147483647] gives [0](0) [Sep 5 10:53:41] DEBUG[9753] res_pjsip.c: 0x7faed80a6530: Callbacks executed [Sep 5 10:53:41] DEBUG[9753] res_pjsip.c: 0x7faed80a6530: wrapper destroyed [Sep 5 10:53:42] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Request msg INVITE/cseq=1 (rdata0x7faed8045968) [Sep 5 10:53:42] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP request (791 bytes) from UDP:104.255.67.151:5070 ---> INVITE sip:7777777777011441975311764@104.236.91.141 SIP/2.0 To: 7777777777011441975311764 From: 100;tag=6a3ce83b Via: SIP/2.0/UDP 104.255.67.151:5070;branch=z9hG4bK-ec150882cd01e212bdb2862d066044f4;rport Call-ID: ec150882cd01e212bdb2862d066044f4 CSeq: 1 INVITE Contact: Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, BYE User-Agent: sipcli/v1.8 Content-Type: application/sdp Content-Length: 284 v=0 o=sipcli-Session 1139699783 662719084 IN IP4 104.255.67.151 s=sipcli c=IN IP4 104.255.67.151 t=0 0 m=audio 5072 RTP/AVP 18 0 8 101 a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv [Sep 5 10:53:42] DEBUG[9369] netsock2.c: Splitting '104.255.67.151:5070' into... [Sep 5 10:53:42] DEBUG[9369] netsock2.c: ...host '104.255.67.151' and port '5070'. [Sep 5 10:53:42] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:42] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:42] DEBUG[10674] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg INVITE/cseq=1 (rdata0x7faed80af338) [Sep 5 10:53:42] DEBUG[10674] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Sep 5 10:53:42] DEBUG[10674] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 100 [Sep 5 10:53:42] DEBUG[10674] pjsip: endpoint .Response msg 401/INVITE/cseq=1 (tdta0x7faed806dcc0) created [Sep 5 10:53:42] DEBUG[10674] netsock2.c: Splitting '104.236.91.141' into... [Sep 5 10:53:42] DEBUG[10674] netsock2.c: ...host '104.236.91.141' and port ''. [Sep 5 10:53:42] DEBUG[10674] netsock2.c: Splitting '104.255.67.151' into... [Sep 5 10:53:42] DEBUG[10674] netsock2.c: ...host '104.255.67.151' and port ''. [Sep 5 10:53:42] DEBUG[10674] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:42] DEBUG[10674] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:42] DEBUG[10674] netsock2.c: Splitting '104.255.67.151:5070' into... [Sep 5 10:53:42] DEBUG[10674] netsock2.c: ...host '104.255.67.151' and port '5070'. [Sep 5 10:53:42] VERBOSE[10674] res_pjsip_logger.c: <--- Transmitting SIP response (589 bytes) to UDP:104.255.67.151:5070 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 104.255.67.151:5070;rport=5070;received=104.255.67.151;branch=z9hG4bK-ec150882cd01e212bdb2862d066044f4 Call-ID: ec150882cd01e212bdb2862d066044f4 From: "100" ;tag=6a3ce83b To: "7777777777011441975311764" ;tag=z9hG4bK-ec150882cd01e212bdb2862d066044f4 CSeq: 1 INVITE WWW-Authenticate: Digest realm="asterisk",nonce="1441468422/f73acdc683218f85f719333898ca6d3b",opaque="425c45836562b16f",algorithm=md5,qop="auth" Server: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:53:42] DEBUG[10674] pjsip: tdta0x7faed806 .Destroying txdata Response msg 401/INVITE/cseq=1 (tdta0x7faed806dcc0) [Sep 5 10:53:43] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=4460 (rdata0x7faed8045968) [Sep 5 10:53:43] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP request (757 bytes) from UDP:216.207.245.1:18997 ---> REGISTER sip:stg.net SIP/2.0 Via: SIP/2.0/UDP 10.24.74.254:5062;branch=z9hG4bK714123952 From: "Scott Griepentrog" ;tag=1348308714 To: "Scott Griepentrog" Call-ID: 1429292974@10.24.74.254 CSeq: 4460 REGISTER Contact: Authorization: Digest username="stgnet", realm="asterisk", nonce="1441468272/32515370199a8a55a76a9e3f9ce06358", uri="sip:stg.net", response="cc1ca122e1cfb084b0f93b8d499a76c2", algorithm=MD5, cnonce="0a4f113b", opaque="1639ad6370837975", qop=auth, nc=00000002 Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE Max-Forwards: 70 User-Agent: Yealink SIP-T28P 2.61.0.80 Expires: 3600 Content-Length: 0 [Sep 5 10:53:43] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:53:43] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:53:43] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:43] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:43] DEBUG[9753] pjsip: sip_endpoint.c Distributing rdata to modules: Request msg REGISTER/cseq=4460 (rdata0x7faed80af338) [Sep 5 10:53:43] DEBUG[9753] res_pjsip_endpoint_identifier_ip.c: No identify sections to match against [Sep 5 10:53:43] DEBUG[9753] res_pjsip_endpoint_identifier_user.c: Retrieved endpoint 100 [Sep 5 10:53:43] DEBUG[9753] pjsip: endpoint .Response msg 401/REGISTER/cseq=4460 (tdta0x7faed806dcc0) created [Sep 5 10:53:43] DEBUG[9753] netsock2.c: Splitting '104.236.91.141' into... [Sep 5 10:53:43] DEBUG[9753] netsock2.c: ...host '104.236.91.141' and port ''. [Sep 5 10:53:43] DEBUG[9753] netsock2.c: Splitting '216.207.245.1' into... [Sep 5 10:53:43] DEBUG[9753] netsock2.c: ...host '216.207.245.1' and port ''. [Sep 5 10:53:43] DEBUG[9753] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:43] DEBUG[9753] netsock2.c: ...host '0.0.0.0' and port '5060'. [Sep 5 10:53:43] DEBUG[9753] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:53:43] DEBUG[9753] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:53:43] VERBOSE[9753] res_pjsip_logger.c: <--- Transmitting SIP response (518 bytes) to UDP:216.207.245.1:18997 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.24.74.254:5062;rport=18997;received=216.207.245.1;branch=z9hG4bK714123952 Call-ID: 1429292974@10.24.74.254 From: "Scott Griepentrog" ;tag=1348308714 To: "Scott Griepentrog" ;tag=z9hG4bK714123952 CSeq: 4460 REGISTER WWW-Authenticate: Digest realm="asterisk",nonce="1441468423/cdd6050f020c1b363b33363d87dd3e46",opaque="1b374ec636fa3d4d",stale=true,algorithm=md5,qop="auth" Server: Asterisk PBX GIT-13-2733638M Content-Length: 0 [Sep 5 10:53:43] DEBUG[9753] pjsip: tdta0x7faed806 .Destroying txdata Response msg 401/REGISTER/cseq=4460 (tdta0x7faed806dcc0) [Sep 5 10:53:44] DEBUG[9369] pjsip: sip_endpoint.c Processing incoming message: Request msg REGISTER/cseq=4461 (rdata0x7faed8045968) [Sep 5 10:53:44] VERBOSE[9369] res_pjsip_logger.c: <--- Received SIP request (758 bytes) from UDP:216.207.245.1:18997 ---> REGISTER sip:stg.net SIP/2.0 Via: SIP/2.0/UDP 10.24.74.254:5062;branch=z9hG4bK1267601465 From: "Scott Griepentrog" ;tag=1348308714 To: "Scott Griepentrog" Call-ID: 1429292974@10.24.74.254 CSeq: 4461 REGISTER Contact: Authorization: Digest username="stgnet", realm="asterisk", nonce="1441468423/cdd6050f020c1b363b33363d87dd3e46", uri="sip:stg.net", response="2c685c38d42946a934369af31845f0bd", algorithm=MD5, cnonce="0a4f113b", opaque="1b374ec636fa3d4d", qop=auth, nc=00000001 Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE Max-Forwards: 70 User-Agent: Yealink SIP-T28P 2.61.0.80 Expires: 3600 Content-Length: 0 [Sep 5 10:53:44] DEBUG[9369] netsock2.c: Splitting '216.207.245.1:18997' into... [Sep 5 10:53:44] DEBUG[9369] netsock2.c: ...host '216.207.245.1' and port '18997'. [Sep 5 10:53:44] DEBUG[9369] netsock2.c: Splitting '0.0.0.0:5060' into... [Sep 5 10:53:44] DEBUG[9369] netsock2.c: ...host '0.0.0.0' and port '5060'.