--- (11 headers 0 lines) --- [2020-10-20 04:01:45] DEBUG[66]: chan_sip.c:4608 __sip_ack: Stopping retransmission on '52624e096d7dab8b3deff2e318a88c2a@{{SBC IP}}:{{SBC PORT}}' of Request 102: Match Found [2020-10-20 04:01:45] DEBUG[66]: chan_sip.c:6666 sip_pvt_dtor: Destroying SIP dialog 52624e096d7dab8b3deff2e318a88c2a@{{SBC IP}}:{{SBC PORT}} Really destroying SIP dialog '52624e096d7dab8b3deff2e318a88c2a@{{SBC IP}}:{{SBC PORT}}' Method: OPTIONS <--- SIP read from UDP:{{provider-IP}}:{{provider-port}} ---> OPTIONS sip:{{provider-username}}@{{SBC IP}}:{{SBC PORT}} SIP/2.0 Via: SIP/2.0/UDP {{provider-IP}};branch=z9hG4bK8a36.93a91135000000000000000000000000.0 To: From: ;tag=47546faa90a5df61ca65b19e3b051eb0-1797 CSeq: 10 OPTIONS Call-ID: 0d8c858a09a99c09-10559@{{provider-IP}} Max-Forwards: 70 Content-Length: 0 User-Agent: VoIP Networks <-------------> --- (9 headers 0 lines) --- [2020-10-20 04:01:55] DEBUG[66]: acl.c:1047 ast_ouraddrfor: For destination '{{provider-IP}}', our source address is '{{SBC IP}}'. [2020-10-20 04:01:55] DEBUG[66]: chan_sip.c:3944 ast_sip_ouraddrfor: Target address {{provider-IP}}:{{provider-port}} is not local, substituting externaddr [2020-10-20 04:01:55] DEBUG[66]: chan_sip.c:3981 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address {{SBC IP}}:{{SBC PORT}} Sending to {{provider-IP}}:{{provider-port}} (NAT) [2020-10-20 04:01:55] DEBUG[66]: chan_sip.c:9086 __sip_alloc: Allocating new SIP dialog for 0d8c858a09a99c09-10559@{{provider-IP}} - OPTIONS (No RTP) Looking for {{provider-username}} in from-sip-external (domain {{SBC IP}}) <--- Transmitting (NAT) to {{provider-IP}}:{{provider-port}} ---> SIP/2.0 200 OK Via: SIP/2.0/UDP {{provider-IP}};branch=z9hG4bK8a36.93a91135000000000000000000000000.0;received={{provider-IP}};rport=5060 From: ;tag=47546faa90a5df61ca65b19e3b051eb0-1797 To: ;tag=as480d23f0 Call-ID: 0d8c858a09a99c09-10559@{{provider-IP}} CSeq: 10 OPTIONS Server: sbc-172.16.5.58 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <------------> [2020-10-20 04:01:55] DEBUG[66]: chan_sip.c:3805 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for {{provider-IP}}:{{provider-port}} Scheduling destruction of SIP dialog '0d8c858a09a99c09-10559@{{provider-IP}}' in 32000 ms (Method: OPTIONS) [2020-10-20 04:01:56] DEBUG[51]: chan_iax2.c:2696 peercnt_remove: ip callno count decremented to 0 for 172.16.5.58 [2020-10-20 04:01:56] DEBUG[54]: chan_iax2.c:2664 peercnt_add: ip callno count incremented to 1 for 172.16.5.58 [2020-10-20 04:01:56] DEBUG[56]: chan_iax2.c:3064 sched_delay_remove: schedule decrement of callno used for 172.16.5.58 in 60 seconds [2020-10-20 04:01:56] DEBUG[56]: chan_iax2.c:11159 socket_process_helper: Peer trunk_asterisk: got pong, lastms 1, historicms 1, maxms 2000 [2020-10-20 04:01:56] DEBUG[47]: res_pjsip_registrar.c:1293 check_expiration_thread: Expiring 0 contacts [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:9086 __sip_alloc: Allocating new SIP dialog for 1f87958c330a22e132c9ffa14522eb2c@[::1]:{{SBC PORT}} - OPTIONS (No RTP) [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3572 obproxy_get: OBPROXY: Not applying OBproxy to this call [2020-10-20 04:01:57] DEBUG[66]: acl.c:1047 ast_ouraddrfor: For destination '{{provider-IP}}', our source address is '{{SBC IP}}'. [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3944 ast_sip_ouraddrfor: Target address {{provider-IP}}:{{provider-port}} is not local, substituting externaddr [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3981 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address {{SBC IP}}:{{SBC PORT}} [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:8875 change_callid_pvt: SIP call-id changed from '1f87958c330a22e132c9ffa14522eb2c@[::1]:{{SBC PORT}}' to '6cfad7362ee9aa461905b1d461c4b896@{{SBC IP}}:{{SBC PORT}}' [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3448 initialize_initreq: Initializing initreq for method OPTIONS - callid 6cfad7362ee9aa461905b1d461c4b896@{{SBC IP}}:{{SBC PORT}} Reliably Transmitting (NAT) to {{provider-IP}}:{{provider-port}}: OPTIONS sip:{{provider-host}} SIP/2.0 Via: SIP/2.0/UDP {{SBC IP}}:{{SBC PORT}};branch=z9hG4bK74bf8c8c;rport Max-Forwards: 70 From: "Unknown" ;tag=as03e81267 To: Contact: Call-ID: 6cfad7362ee9aa461905b1d461c4b896@{{SBC IP}}:{{SBC PORT}} CSeq: 102 OPTIONS User-Agent: sbc-172.16.5.58 Date: Tue, 20 Oct 2020 04:01:57 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3805 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for {{provider-IP}}:{{provider-port}} [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:9086 __sip_alloc: Allocating new SIP dialog for 75c6ae7512712bda17bd83952360d2b8@[::1]:{{SBC PORT}} - OPTIONS (No RTP) [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3572 obproxy_get: OBPROXY: Not applying OBproxy to this call [2020-10-20 04:01:57] DEBUG[66]: acl.c:1047 ast_ouraddrfor: For destination '172.16.5.56', our source address is '172.16.5.58'. [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3981 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 172.16.5.58:{{SBC PORT}} [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:8875 change_callid_pvt: SIP call-id changed from '75c6ae7512712bda17bd83952360d2b8@[::1]:{{SBC PORT}}' to '610a40bb5f3cef7a59c6328618dd8e5f@172.16.5.58:{{SBC PORT}}' [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3448 initialize_initreq: Initializing initreq for method OPTIONS - callid 610a40bb5f3cef7a59c6328618dd8e5f@172.16.5.58:{{SBC PORT}} Reliably Transmitting (NAT) to 172.16.5.56:{{port2}}: OPTIONS sip:172.16.5.56 SIP/2.0 Via: SIP/2.0/UDP 172.16.5.58:{{SBC PORT}};branch=z9hG4bK3f476c66;rport Max-Forwards: 70 From: "Unknown" ;tag=as5e728acc To: Contact: Call-ID: 610a40bb5f3cef7a59c6328618dd8e5f@172.16.5.58:{{SBC PORT}} CSeq: 102 OPTIONS User-Agent: sbc-172.16.5.58 Date: Tue, 20 Oct 2020 04:01:57 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3805 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.16.5.56:{{port2}} <--- SIP read from UDP:{{provider-IP}}:{{provider-port}} ---> SIP/2.0 200 OK Via: SIP/2.0/UDP {{SBC IP}}:{{SBC PORT}};branch=z9hG4bK74bf8c8c;rport={{SBC-port}};received={{SBC IP}} From: "Unknown" ;tag=as03e81267 To: ;tag=dc6cbcde051f1f52327d3ee3c1495fc6.2640 Call-ID: 6cfad7362ee9aa461905b1d461c4b896@{{SBC IP}}:{{SBC PORT}} CSeq: 102 OPTIONS Server: VoIP Networks Content-Length: 0 <-------------> --- (8 headers 0 lines) --- [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:4608 __sip_ack: Stopping retransmission on '6cfad7362ee9aa461905b1d461c4b896@{{SBC IP}}:{{SBC PORT}}' of Request 102: Match Found <--- SIP read from UDP:172.16.5.56:{{port2}} ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.5.58:{{SBC PORT}};branch=z9hG4bK3f476c66;received=172.16.5.58;rport={{SBC-port}} From: "Unknown" ;tag=as5e728acc To: ;tag=as0b345fe5 Call-ID: 610a40bb5f3cef7a59c6328618dd8e5f@172.16.5.58:{{SBC PORT}} CSeq: 102 OPTIONS Server: wave2-172.16.5.56 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <-------------> --- (12 headers 0 lines) --- [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:4608 __sip_ack: Stopping retransmission on '610a40bb5f3cef7a59c6328618dd8e5f@172.16.5.58:{{SBC PORT}}' of Request 102: Match Found [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:6666 sip_pvt_dtor: Destroying SIP dialog 6cfad7362ee9aa461905b1d461c4b896@{{SBC IP}}:{{SBC PORT}} Really destroying SIP dialog '6cfad7362ee9aa461905b1d461c4b896@{{SBC IP}}:{{SBC PORT}}' Method: OPTIONS [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:6666 sip_pvt_dtor: Destroying SIP dialog 610a40bb5f3cef7a59c6328618dd8e5f@172.16.5.58:{{SBC PORT}} Really destroying SIP dialog '610a40bb5f3cef7a59c6328618dd8e5f@172.16.5.58:{{SBC PORT}}' Method: OPTIONS [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:9086 __sip_alloc: Allocating new SIP dialog for 04fbc1b44769f93651394a8e5b54f9dd@[::1]:{{SBC PORT}} - OPTIONS (No RTP) [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3572 obproxy_get: OBPROXY: Not applying OBproxy to this call [2020-10-20 04:01:57] DEBUG[66]: acl.c:1047 ast_ouraddrfor: For destination '{{provider-IP}}', our source address is '{{SBC IP}}'. [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3944 ast_sip_ouraddrfor: Target address {{provider-IP}}:{{provider-port}} is not local, substituting externaddr [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3981 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address {{SBC IP}}:{{SBC PORT}} [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:8875 change_callid_pvt: SIP call-id changed from '04fbc1b44769f93651394a8e5b54f9dd@[::1]:{{SBC PORT}}' to '661acee16528d9983a46c2117bf4ed35@{{SBC IP}}:{{SBC PORT}}' [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3448 initialize_initreq: Initializing initreq for method OPTIONS - callid 661acee16528d9983a46c2117bf4ed35@{{SBC IP}}:{{SBC PORT}} Reliably Transmitting (NAT) to {{provider-IP}}:{{provider-port}}: OPTIONS sip:{{provider-host}} SIP/2.0 Via: SIP/2.0/UDP {{SBC IP}}:{{SBC PORT}};branch=z9hG4bK6ddbb407;rport Max-Forwards: 70 From: "Unknown" ;tag=as0cc1dd46 To: Contact: Call-ID: 661acee16528d9983a46c2117bf4ed35@{{SBC IP}}:{{SBC PORT}} CSeq: 102 OPTIONS User-Agent: sbc-172.16.5.58 Date: Tue, 20 Oct 2020 04:01:57 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3805 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for {{provider-IP}}:{{provider-port}} <--- SIP read from UDP:{{provider-IP}}:{{provider-port}} ---> SIP/2.0 200 OK Via: SIP/2.0/UDP {{SBC IP}}:{{SBC PORT}};branch=z9hG4bK6ddbb407;rport={{SBC-port}};received={{SBC IP}} From: "Unknown" ;tag=as0cc1dd46 To: ;tag=dc6cbcde051f1f52327d3ee3c1495fc6.7ce1 Call-ID: 661acee16528d9983a46c2117bf4ed35@{{SBC IP}}:{{SBC PORT}} CSeq: 102 OPTIONS Server: VoIP Networks Content-Length: 0 <-------------> --- (8 headers 0 lines) --- [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:4608 __sip_ack: Stopping retransmission on '661acee16528d9983a46c2117bf4ed35@{{SBC IP}}:{{SBC PORT}}' of Request 102: Match Found [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:6666 sip_pvt_dtor: Destroying SIP dialog 661acee16528d9983a46c2117bf4ed35@{{SBC IP}}:{{SBC PORT}} Really destroying SIP dialog '661acee16528d9983a46c2117bf4ed35@{{SBC IP}}:{{SBC PORT}}' Method: OPTIONS [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:9086 __sip_alloc: Allocating new SIP dialog for 6933c19265ec7ae475800eb63bac0b7d@[::1]:{{SBC PORT}} - OPTIONS (No RTP) [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3572 obproxy_get: OBPROXY: Not applying OBproxy to this call [2020-10-20 04:01:57] DEBUG[66]: acl.c:1047 ast_ouraddrfor: For destination '172.16.5.56', our source address is '172.16.5.58'. [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3981 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 172.16.5.58:{{SBC PORT}} [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:8875 change_callid_pvt: SIP call-id changed from '6933c19265ec7ae475800eb63bac0b7d@[::1]:{{SBC PORT}}' to '5bfb914c3d24432e307b5d0b3bdb0bc7@172.16.5.58:{{SBC PORT}}' [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3448 initialize_initreq: Initializing initreq for method OPTIONS - callid 5bfb914c3d24432e307b5d0b3bdb0bc7@172.16.5.58:{{SBC PORT}} Reliably Transmitting (NAT) to 172.16.5.56:{{port}}: OPTIONS sip:172.16.5.56 SIP/2.0 Via: SIP/2.0/UDP 172.16.5.58:{{SBC PORT}};branch=z9hG4bK48362db6;rport Max-Forwards: 70 From: "Unknown" ;tag=as70229077 To: Contact: Call-ID: 5bfb914c3d24432e307b5d0b3bdb0bc7@172.16.5.58:{{SBC PORT}} CSeq: 102 OPTIONS User-Agent: sbc-172.16.5.58 Date: Tue, 20 Oct 2020 04:01:57 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:3805 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.16.5.56:{{port}} <--- SIP read from UDP:172.16.5.56:{{port}} ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.5.58:{{SBC PORT}};branch=z9hG4bK48362db6;received=172.16.5.58;rport={{SBC-port}} From: "Unknown" ;tag=as70229077 To: ;tag=as20c03337 Call-ID: 5bfb914c3d24432e307b5d0b3bdb0bc7@172.16.5.58:{{SBC PORT}} CSeq: 102 OPTIONS Server: wave2-172.16.5.56 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <-------------> --- (12 headers 0 lines) --- [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:4608 __sip_ack: Stopping retransmission on '5bfb914c3d24432e307b5d0b3bdb0bc7@172.16.5.58:{{SBC PORT}}' of Request 102: Match Found [2020-10-20 04:01:57] DEBUG[66]: chan_sip.c:6666 sip_pvt_dtor: Destroying SIP dialog 5bfb914c3d24432e307b5d0b3bdb0bc7@172.16.5.58:{{SBC PORT}} Really destroying SIP dialog '5bfb914c3d24432e307b5d0b3bdb0bc7@172.16.5.58:{{SBC PORT}}' Method: OPTIONS <--- SIP read from UDP:{{office IP}}:4007 ---> REGISTER sip:{{SBC IP}}:{{SBC PORT}} SIP/2.0 Via: SIP/2.0/UDP 192.168.115.71:{{provider-port}};rport;branch=z9hG4bKPjb6456838-c092-45ba-a8c9-908c9dc55534 Max-Forwards: 70 From: "SBC phone3" ;tag=a08973ca-39e1-4f58-8c69-6403004fac4b To: "SBC phone3" Call-ID: 1f1d864e-d65c-4ed5-ad64-513003eba9a6 CSeq: 39933 REGISTER User-Agent: Jami Daemon 9.5.0 (linux) Contact: Expires: 60 Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, OPTIONS, MESSAGE, PUBLISH Content-Length: 0 <-------------> --- (12 headers 0 lines) --- [2020-10-20 04:02:00] DEBUG[66]: acl.c:1047 ast_ouraddrfor: For destination '{{office IP}}', our source address is '{{SBC IP}}'. [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:3944 ast_sip_ouraddrfor: Target address {{office IP}}:4007 is not local, substituting externaddr [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:3981 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address {{SBC IP}}:{{SBC PORT}} [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:19168 check_for_nat: NAT detected for 192.168.115.71 / {{office IP}} Sending to {{office IP}}:4007 (NAT) [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:9086 __sip_alloc: Allocating new SIP dialog for 1f1d864e-d65c-4ed5-ad64-513003eba9a6 - REGISTER (No RTP) [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:19168 check_for_nat: NAT detected for 192.168.115.71 / {{office IP}} Sending to {{office IP}}:4007 (NAT) <--- Transmitting (NAT) to {{office IP}}:4007 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.115.71:{{provider-port}};branch=z9hG4bKPjb6456838-c092-45ba-a8c9-908c9dc55534;received={{office IP}};rport=4007 From: "SBC phone3" ;tag=a08973ca-39e1-4f58-8c69-6403004fac4b To: "SBC phone3" ;tag=as042fe4ab Call-ID: 1f1d864e-d65c-4ed5-ad64-513003eba9a6 CSeq: 39933 REGISTER Server: sbc-172.16.5.58 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="3384b240" Content-Length: 0 <------------> [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:3805 __sip_xmit: Trying to put 'SIP/2.0 401' onto UDP socket destined for {{office IP}}:4007 Scheduling destruction of SIP dialog '1f1d864e-d65c-4ed5-ad64-513003eba9a6' in 32000 ms (Method: REGISTER) <--- SIP read from UDP:{{office IP}}:4007 ---> REGISTER sip:{{SBC IP}}:{{SBC PORT}} SIP/2.0 Via: SIP/2.0/UDP 192.168.115.71:{{provider-port}};rport;branch=z9hG4bKPj07adee26-4edc-4d78-a322-14b53775fcda Max-Forwards: 70 From: "SBC phone3" ;tag=a08973ca-39e1-4f58-8c69-6403004fac4b To: "SBC phone3" Call-ID: 1f1d864e-d65c-4ed5-ad64-513003eba9a6 CSeq: 39934 REGISTER User-Agent: Jami Daemon 9.5.0 (linux) Contact: Expires: 60 Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, OPTIONS, MESSAGE, PUBLISH Authorization: Digest username="phone3", realm="asterisk", nonce="3384b240", uri="sip:{{SBC IP}}:{{SBC PORT}}", response="a4f0ea44ffe08f86bbe4af88a7509772", algorithm=MD5 Content-Length: 0 <-------------> --- (13 headers 0 lines) --- [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:19168 check_for_nat: NAT detected for 192.168.115.71 / {{office IP}} Sending to {{office IP}}:4007 (NAT) [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:17126 parse_register_contact: Store REGISTER's src-IP:port for call routing. [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:17290 build_path: build_path: do not use Path headers [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:9086 __sip_alloc: Allocating new SIP dialog for 543a3d9765629cc64656f32f2d0005e8@[::1]:{{SBC PORT}} - OPTIONS (No RTP) [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:3572 obproxy_get: OBPROXY: Not applying OBproxy to this call [2020-10-20 04:02:00] DEBUG[66]: acl.c:1047 ast_ouraddrfor: For destination '{{office IP}}', our source address is '{{SBC IP}}'. [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:3944 ast_sip_ouraddrfor: Target address {{office IP}}:4007 is not local, substituting externaddr [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:3981 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address {{SBC IP}}:{{SBC PORT}} [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:8875 change_callid_pvt: SIP call-id changed from '543a3d9765629cc64656f32f2d0005e8@[::1]:{{SBC PORT}}' to '0637de73009e45a54636668912a5836a@{{SBC IP}}:{{SBC PORT}}' [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:3448 initialize_initreq: Initializing initreq for method OPTIONS - callid 0637de73009e45a54636668912a5836a@{{SBC IP}}:{{SBC PORT}} Reliably Transmitting (NAT) to {{office IP}}:4007: OPTIONS sip:phone3@{{office IP}}:4007 SIP/2.0 Via: SIP/2.0/UDP {{SBC IP}}:{{SBC PORT}};branch=z9hG4bK2d3de47d;rport Max-Forwards: 70 From: "Unknown" ;tag=as6347d289 To: Contact: Call-ID: 0637de73009e45a54636668912a5836a@{{SBC IP}}:{{SBC PORT}} CSeq: 102 OPTIONS User-Agent: sbc-172.16.5.58 Date: Tue, 20 Oct 2020 04:02:00 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:3805 __sip_xmit: Trying to put 'OPTIONS sip' onto UDP socket destined for {{office IP}}:4007 <--- Transmitting (NAT) to {{office IP}}:4007 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.115.71:{{provider-port}};branch=z9hG4bKPj07adee26-4edc-4d78-a322-14b53775fcda;received={{office IP}};rport=4007 From: "SBC phone3" ;tag=a08973ca-39e1-4f58-8c69-6403004fac4b To: "SBC phone3" ;tag=as042fe4ab Call-ID: 1f1d864e-d65c-4ed5-ad64-513003eba9a6 CSeq: 39934 REGISTER Server: sbc-172.16.5.58 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Expires: 60 Contact: ;expires=60 Date: Tue, 20 Oct 2020 04:02:00 GMT Content-Length: 0 <------------> [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:3805 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for {{office IP}}:4007 Scheduling destruction of SIP dialog '1f1d864e-d65c-4ed5-ad64-513003eba9a6' in 32000 ms (Method: REGISTER) [2020-10-20 04:02:00] DEBUG[14]: chan_sip.c:30738 sip_devicestate: Checking device state for peer phone3 [2020-10-20 04:02:00] DEBUG[14]: devicestate.c:466 do_state_change: Changing state for SIP/phone3 - state 1 (Not in use) <--- SIP read from UDP:{{office IP}}:4007 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP {{SBC IP}}:{{SBC PORT}};rport={{SBC-port}};received={{SBC IP}};branch=z9hG4bK2d3de47d Call-ID: 0637de73009e45a54636668912a5836a@{{SBC IP}}:{{SBC PORT}} From: "Unknown" ;tag=as6347d289 To: ;tag=z9hG4bK2d3de47d CSeq: 102 OPTIONS Allow: PRACK, SUBSCRIBE, NOTIFY, REFER, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, OPTIONS, MESSAGE, PUBLISH Accept: message/sipfrag;version=2.0, application/pidf+xml, application/xpidf+xml, application/sdp, text/plain, application/sdp, application/im-iscomposing+xml Supported: replaces, 100rel Allow-Events: refer, presence Content-Length: 0 <-------------> --- (11 headers 0 lines) --- [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:4608 __sip_ack: Stopping retransmission on '0637de73009e45a54636668912a5836a@{{SBC IP}}:{{SBC PORT}}' of Request 102: Match Found [2020-10-20 04:02:00] DEBUG[66]: chan_sip.c:6666 sip_pvt_dtor: Destroying SIP dialog 0637de73009e45a54636668912a5836a@{{SBC IP}}:{{SBC PORT}} Really destroying SIP dialog '0637de73009e45a54636668912a5836a@{{SBC IP}}:{{SBC PORT}}' Method: OPTIONS [2020-10-20 04:02:06] DEBUG[66]: chan_sip.c:4432 __sip_autodestruct: Auto destroying SIP dialog '3e2bd1303ca9d5013ad64931341073d3@172.16.5.56:{{port2}}' [2020-10-20 04:02:06] DEBUG[66]: chan_sip.c:6666 sip_pvt_dtor: Destroying SIP dialog 3e2bd1303ca9d5013ad64931341073d3@172.16.5.56:{{port2}} Really destroying SIP dialog '3e2bd1303ca9d5013ad64931341073d3@172.16.5.56:{{port2}}' Method: OPTIONS <--- SIP read from UDP:172.16.5.56:{{port}} ---> OPTIONS sip:172.16.5.58 SIP/2.0 Via: SIP/2.0/UDP 172.16.5.56:{{port}};branch=z9hG4bK4e74a30c;rport Max-Forwards: 70 From: "Unknown" ;tag=as4b763d1e To: Contact: Call-ID: 472f7a6031cd0e3f3089ed2c76586a9c@172.16.5.56:{{port}} CSeq: 102 OPTIONS User-Agent: wave2-172.16.5.56 Date: Tue, 20 Oct 2020 04:02:06 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <-------------> --- (13 headers 0 lines) --- [2020-10-20 04:02:06] DEBUG[66]: acl.c:1047 ast_ouraddrfor: For destination '172.16.5.56', our source address is '172.16.5.58'. [2020-10-20 04:02:06] DEBUG[66]: chan_sip.c:3981 ast_sip_ouraddrfor: Setting AST_TRANSPORT_UDP with address 172.16.5.58:{{SBC PORT}} Sending to 172.16.5.56:{{port}} (NAT) [2020-10-20 04:02:06] DEBUG[66]: chan_sip.c:9086 __sip_alloc: Allocating new SIP dialog for 472f7a6031cd0e3f3089ed2c76586a9c@172.16.5.56:{{port}} - OPTIONS (No RTP) Looking for s in from-sip-external (domain 172.16.5.58) <--- Transmitting (NAT) to 172.16.5.56:{{port}} ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.16.5.56:{{port}};branch=z9hG4bK4e74a30c;received=172.16.5.56;rport={{SBC-port}} From: "Unknown" ;tag=as4b763d1e To: ;tag=as67024da7 Call-ID: 472f7a6031cd0e3f3089ed2c76586a9c@172.16.5.56:{{port}} CSeq: 102 OPTIONS Server: sbc-172.16.5.58 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <------------> [2020-10-20 04:02:06] DEBUG[66]: chan_sip.c:3805 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 172.16.5.56:{{port}} Scheduling destruction of SIP dialog '472f7a6031cd0e3f3089ed2c76586a9c@172.16.5.56:{{port}}' in 32000 ms (Method: OPTIONS) sbc01*CLI>