[Sep 1 20:48:58] Asterisk 16.8.0.ips built by root @ 68bccacd-6b28-4bda-ab4b-93a9f0acf152-h448x on a x86_64 running Linux on 2020-07-13 05:15:02 UTC [Sep 1 20:48:58] VERBOSE[1459] loader.c: Reloading module 'logger' (Logger) [Sep 1 20:48:58] DEBUG[1459] config.c: Parsing /etc/asterisk/logger.conf [Sep 1 20:48:58] VERBOSE[1459] logger.c: Asterisk Queue Logger restarted [Sep 1 20:48:58] DEBUG[1459] config.c: Parsing /etc/asterisk/logger.conf [Sep 1 20:48:58] VERBOSE[1459] logger.c: Asterisk Queue Logger restarted [Sep 1 20:49:04] DEBUG[1298] res_pjsip_registrar.c: Woke up at 1599007744 Interval: 30 [Sep 1 20:49:04] DEBUG[1298] res_pjsip_registrar.c: Expiring 0 contacts [Sep 1 20:49:07] DEBUG[1459] stasis.c: Creating topic. name: channel:1599007747.11, detail: [Sep 1 20:49:07] DEBUG[1459] stasis.c: Topic 'channel:1599007747.11': 0x555896d235b0 created [Sep 1 20:49:07] DEBUG[1459] stasis.c: Creating topic. name: cache:30/channel:1599007747.11, detail: [Sep 1 20:49:07] DEBUG[1459] stasis.c: Topic 'cache:30/channel:1599007747.11': 0x147de40408e0 created [Sep 1 20:49:07] DEBUG[1459] channel.c: Channel 0x147de405b460 'Local/s@originate-leg2-00000002;1' allocated [Sep 1 20:49:07] DEBUG[1459] stasis.c: Creating topic. name: channel:1599007747.12, detail: [Sep 1 20:49:07] DEBUG[1459] stasis.c: Topic 'channel:1599007747.12': 0x147de4092a70 created [Sep 1 20:49:07] DEBUG[1459] stasis.c: Creating topic. name: cache:31/channel:1599007747.12, detail: [Sep 1 20:49:07] DEBUG[1459] stasis.c: Topic 'cache:31/channel:1599007747.12': 0x147de4091800 created [Sep 1 20:49:07] DEBUG[1459] channel.c: Channel 0x147de405d120 'Local/s@originate-leg2-00000002;2' allocated [Sep 1 20:49:07] VERBOSE[1475] dial.c: Called s@originate-leg2 [Sep 1 20:49:07] DEBUG[1476][C-00000005] pbx.c: Launching 'Dial' [Sep 1 20:49:07] VERBOSE[1476][C-00000005] pbx.c: Executing [s@originate-leg2:1] Dial("Local/s@originate-leg2-00000002;2", "SIP/9000,60,U(orig-ans)") in new stack [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Asked to create a SIP channel with formats: (slin) [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Allocating new SIP dialog for 10c3f5041e1a67911fd085022e5aa3ca@[fe80::630d:d8c5:2cd9:85b8]:5060 - INVITE (No RTP) [Sep 1 20:49:07] DEBUG[1476][C-00000005] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x147de80193b0' [Sep 1 20:49:07] DEBUG[1476][C-00000005] res_rtp_asterisk.c: Allocated port 15438 for RTP instance '0x147de80193b0' [Sep 1 20:49:07] DEBUG[1476][C-00000005] res_rtp_asterisk.c: Creating ICE session 0.0.0.0:15438 (15438) for RTP instance '0x147de80193b0' [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: Splitting '10.0.2.15' into... [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: ...host '10.0.2.15' and port ''. [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: Splitting '10.0.2.15' into... [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: ...host '10.0.2.15' and port ''. [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: Splitting '192.168.33.20' into... [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: ...host '192.168.33.20' and port ''. [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: Splitting '192.168.33.20' into... [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: ...host '192.168.33.20' and port ''. [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:49:07] DEBUG[1476][C-00000005] rtp_engine.c: RTP instance '0x147de80193b0' is setup and ready to go [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: Splitting 'pstn8' into... [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: ...host 'pstn8' and port ''. [Sep 1 20:49:07] DEBUG[1476][C-00000005] acl.c: Multiple addresses. Using the first only [Sep 1 20:49:07] DEBUG[1476][C-00000005] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x147de80193b0' [Sep 1 20:49:07] VERBOSE[1476][C-00000005] netsock2.c: Using SIP RTP CoS mark 5 [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Setting NAT on RTP to Off [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Sep 1 20:49:07] DEBUG[1476][C-00000005] acl.c: For destination '172.28.128.200', our source address is '172.28.128.20'. [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: Splitting '172.28.128.200:5060' into... [Sep 1 20:49:07] DEBUG[1476][C-00000005] netsock2.c: ...host '172.28.128.200' and port '5060'. [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Setting NAT on RTP to Off [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: SIP call-id changed from '10c3f5041e1a67911fd085022e5aa3ca@[fe80::630d:d8c5:2cd9:85b8]:5060' to '226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060' [Sep 1 20:49:07] DEBUG[1476][C-00000005] stasis.c: Creating topic. name: channel:1599007747.13, detail: [Sep 1 20:49:07] DEBUG[1476][C-00000005] stasis.c: Topic 'channel:1599007747.13': 0x555896cf39d0 created [Sep 1 20:49:07] DEBUG[1476][C-00000005] stasis.c: Creating topic. name: cache:32/channel:1599007747.13, detail: [Sep 1 20:49:07] DEBUG[1476][C-00000005] stasis.c: Topic 'cache:32/channel:1599007747.13': 0x555896e09790 created [Sep 1 20:49:07] DEBUG[1476][C-00000005] channel.c: Channel 0x147de804f670 'SIP/9000-00000001' allocated [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: *** Our native formats are (alaw) [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: *** Joint capabilities are (nothing) [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: *** Our capabilities are (alaw|ulaw) [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: *** Our preferred formats from the incoming channel are (slin) [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: This channel will not be able to handle video. [Sep 1 20:49:07] DEBUG[1476][C-00000005] channel_internal_api.c: Channel Call ID changing from [C-00000005] to [C-00000005] [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Outgoing Call for 9000 [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Updating call counter for outgoing call [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: ** Our capability: (alaw|ulaw) Video flag: False Text flag: False [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: ** Our prefcodec: (slin) [Sep 1 20:49:07] VERBOSE[1476][C-00000005] chan_sip.c: Audio is at 15438 [Sep 1 20:49:07] VERBOSE[1476][C-00000005] chan_sip.c: Adding codec alaw to SDP [Sep 1 20:49:07] VERBOSE[1476][C-00000005] chan_sip.c: Adding codec ulaw to SDP [Sep 1 20:49:07] VERBOSE[1476][C-00000005] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: -- Done with adding codecs to SDP [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Done building SDP. Settling with this capability: (alaw|ulaw) [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Initializing initreq for method INVITE - callid 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 0 [ 84]: INVITE sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6bf6da0a [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 3 [ 66]: From: "Anonymous" ;tag=as165dcdc6 [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 4 [ 75]: To: [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 5 [ 43]: Contact: [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 6 [ 60]: Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 8 [ 35]: User-Agent: Asterisk PBX 16.8.0.ips [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 9 [ 35]: Date: Wed, 02 Sep 2020 00:49:07 GMT [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 10 [ 21]: Session-Expires: 1800 [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 12 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [Sep 1 20:49:07] VERBOSE[1476][C-00000005] chan_sip.c: Reliably Transmitting (no NAT) to 172.28.128.200:5060: INVITE sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6bf6da0a Max-Forwards: 70 From: "Anonymous" ;tag=as165dcdc6 To: Contact: Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 CSeq: 102 INVITE User-Agent: Asterisk PBX 16.8.0.ips Date: Wed, 02 Sep 2020 00:49:07 GMT Session-Expires: 1800 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Type: application/sdp Content-Length: 267 v=0 o=root 523195980 523195980 IN IP4 172.28.128.20 s=Asterisk PBX 16.8.0.ips c=IN IP4 172.28.128.20 t=0 0 m=audio 15438 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=maxptime:150 a=sendrecv --- [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #15 [Sep 1 20:49:07] DEBUG[1476][C-00000005] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 172.28.128.200:5060 [Sep 1 20:49:07] VERBOSE[1476][C-00000005] app_dial.c: Called SIP/9000 [Sep 1 20:49:07] DEBUG[1476][C-00000005] channel.c: Channel SIP/9000-00000001 setting read format path: alaw -> slin [Sep 1 20:49:07] DEBUG[1476][C-00000005] channel.c: Channel Local/s@originate-leg2-00000002;2 setting write format path: slin -> slin [Sep 1 20:49:07] DEBUG[1476][C-00000005] channel.c: Channel Local/s@originate-leg2-00000002;2 setting read format path: slin -> slin [Sep 1 20:49:07] DEBUG[1476][C-00000005] channel.c: Channel SIP/9000-00000001 setting write format path: slin -> alaw [Sep 1 20:49:08] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.200:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6bf6da0a To: From: "Anonymous" ;tag=as165dcdc6 Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 CSeq: 102 INVITE Content-Length: 0 <-------------> [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6bf6da0a [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 2 [ 75]: To: [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 3 [ 66]: From: "Anonymous" ;tag=as165dcdc6 [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 4 [ 60]: Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Sep 1 20:49:08] VERBOSE[1321] chan_sip.c: --- (7 headers 0 lines) --- [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: = Looking for Call ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 (Checking To) --From tag as165dcdc6 --To-tag [Sep 1 20:49:08] DEBUG[1321][C-00000005] chan_sip.c: *** SIP TIMER: Cancelling retransmission #15 - INVITE (got response) [Sep 1 20:49:08] DEBUG[1321][C-00000005] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060' Request 102: Found [Sep 1 20:49:08] DEBUG[1321][C-00000005] chan_sip.c: SIP response 100 to standard invite [Sep 1 20:49:08] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.200:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6bf6da0a Contact: To: ;tag=92cf4279 From: "Anonymous";tag=as165dcdc6 Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 CSeq: 102 INVITE User-Agent: Z 3.3.25608 r25552 Content-Length: 0 <-------------> [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6bf6da0a [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 2 [ 80]: Contact: [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 3 [ 88]: To: ;tag=92cf4279 [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 4 [ 65]: From: "Anonymous";tag=as165dcdc6 [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 5 [ 60]: Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 7 [ 30]: User-Agent: Z 3.3.25608 r25552 [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Sep 1 20:49:08] VERBOSE[1321] chan_sip.c: --- (9 headers 0 lines) --- [Sep 1 20:49:08] DEBUG[1321] chan_sip.c: = Looking for Call ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 (Checking To) --From tag as165dcdc6 --To-tag 92cf4279 [Sep 1 20:49:08] DEBUG[1321][C-00000005] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060' Request 102: Found [Sep 1 20:49:08] DEBUG[1321][C-00000005] chan_sip.c: SIP response 180 to standard invite [Sep 1 20:49:08] VERBOSE[1321][C-00000005] sip/route.c: sip_route_dump: route/path hop: [Sep 1 20:49:08] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for SIP - 9000 [Sep 1 20:49:08] DEBUG[1270] chan_sip.c: Checking device state for peer 9000 [Sep 1 20:49:08] DEBUG[1270] devicestate.c: Changing state for SIP/9000 - state 1 (Not in use) [Sep 1 20:49:08] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for SIP - 9000 [Sep 1 20:49:08] DEBUG[1270] chan_sip.c: Checking device state for peer 9000 [Sep 1 20:49:08] DEBUG[1270] devicestate.c: Changing state for SIP/9000 - state 1 (Not in use) [Sep 1 20:49:08] DEBUG[1339] app_queue.c: Device 'SIP/9000' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 1 20:49:08] VERBOSE[1476][C-00000005] app_dial.c: SIP/9000-00000001 is ringing [Sep 1 20:49:08] VERBOSE[1475] dial.c: Local/s@originate-leg2-00000002;1 is ringing [Sep 1 20:49:08] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for Local - s@originate-leg2 [Sep 1 20:49:08] DEBUG[1270] devicestate.c: Changing state for Local/s@originate-leg2 - state 2 (In use) [Sep 1 20:49:08] DEBUG[1339] app_queue.c: Device 'Local/s@originate-leg2' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 1 20:49:09] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6bf6da0a Require: timer Contact: To: ;tag=92cf4279 From: "Anonymous";tag=as165dcdc6 Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 CSeq: 102 INVITE Session-Expires: 1800;refresher=uac Min-SE: 90 Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Content-Type: application/sdp Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri User-Agent: Z 3.3.25608 r25552 Allow-Events: presence, kpml Content-Length: 111 v=0 o=Z 0 2 IN IP4 172.28.128.200 s=Z c=IN IP4 172.28.128.200 t=0 0 m=audio 8000 RTP/AVP 8 0 a=sendrecv <-------------> [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6bf6da0a [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 2 [ 14]: Require: timer [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 3 [ 80]: Contact: [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 4 [ 88]: To: ;tag=92cf4279 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 5 [ 65]: From: "Anonymous";tag=as165dcdc6 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 6 [ 60]: Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 8 [ 35]: Session-Expires: 1800;refresher=uac [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 9 [ 10]: Min-SE: 90 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 11 [ 29]: Content-Type: application/sdp [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 12 [ 74]: Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 13 [ 30]: User-Agent: Z 3.3.25608 r25552 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 14 [ 28]: Allow-Events: presence, kpml [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 15 [ 19]: Content-Length: 111 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Header 16 [ 0]: [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Body 0 [ 3]: v=0 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Body 1 [ 29]: o=Z 0 2 IN IP4 172.28.128.200 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Body 2 [ 3]: s=Z [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Body 3 [ 23]: c=IN IP4 172.28.128.200 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Body 4 [ 5]: t=0 0 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Body 5 [ 24]: m=audio 8000 RTP/AVP 8 0 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Body 6 [ 10]: a=sendrecv [Sep 1 20:49:09] VERBOSE[1321] chan_sip.c: --- (16 headers 7 lines) --- [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: = Looking for Call ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 (Checking To) --From tag as165dcdc6 --To-tag 92cf4279 [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Acked pending invite 102 [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Stopping retransmission on '226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060' of Request 102: Match Found [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: SIP response 200 to standard invite [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Processing session-level SDP o=Z 0 2 IN IP4 172.28.128.200... OK. [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Processing session-level SDP s=Z... UNSUPPORTED OR FAILED. [Sep 1 20:49:09] DEBUG[1321][C-00000005] netsock2.c: Splitting '172.28.128.200' into... [Sep 1 20:49:09] DEBUG[1321][C-00000005] netsock2.c: ...host '172.28.128.200' and port ''. [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Processing session-level SDP c=IN IP4 172.28.128.200... OK. [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Sep 1 20:49:09] VERBOSE[1321][C-00000005] chan_sip.c: Found RTP audio format 8 [Sep 1 20:49:09] DEBUG[1321][C-00000005] rtp_engine.c: Setting tx payload type 8 based on m type on 0x147da33913b0 [Sep 1 20:49:09] VERBOSE[1321][C-00000005] chan_sip.c: Found RTP audio format 0 [Sep 1 20:49:09] DEBUG[1321][C-00000005] rtp_engine.c: Setting tx payload type 0 based on m type on 0x147da33913b0 [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Sep 1 20:49:09] VERBOSE[1321][C-00000005] chan_sip.c: Capabilities: us - (alaw|ulaw), peer - audio=(ulaw|alaw)/video=(nothing)/text=(nothing), combined - (alaw|ulaw) [Sep 1 20:49:09] VERBOSE[1321][C-00000005] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x0 (nothing), combined - 0x0 (nothing) [Sep 1 20:49:09] DEBUG[1321][C-00000005] res_rtp_asterisk.c: Set role to CONTROLLING (0x147de80193b0) [Sep 1 20:49:09] DEBUG[1321][C-00000005] res_rtp_asterisk.c: Set role failed; no ice instance (0x147de80193b0) [Sep 1 20:49:09] DEBUG[1321][C-00000005] acl.c: For destination '172.28.128.200', our source address is '172.28.128.20'. [Sep 1 20:49:09] DEBUG[1321][C-00000005] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x147de80193b0' [Sep 1 20:49:09] VERBOSE[1321][C-00000005] res_rtp_asterisk.c: 0x147de8019d50 -- Strict RTP learning after remote address set to: 172.28.128.200:8000 [Sep 1 20:49:09] VERBOSE[1321][C-00000005] chan_sip.c: Peer audio RTP is at port 172.28.128.200:8000 [Sep 1 20:49:09] DEBUG[1321][C-00000005] rtp_engine.c: Copying tx payload mapping 0 (0x555895424148) from 0x147da33913b0 to 0x147de8019588 [Sep 1 20:49:09] DEBUG[1321][C-00000005] rtp_engine.c: Copying tx payload mapping 8 (0x555895741418) from 0x147da33913b0 to 0x147de8019588 [Sep 1 20:49:09] DEBUG[1321][C-00000005] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x147de80193b0' [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: We're settling with these formats: (alaw|ulaw) [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: We have an owner, now see if we need to change this call [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Setting native formats after processing SDP. peer joint formats (alaw|ulaw), old nativeformats (alaw) [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Updating call counter for outgoing call [Sep 1 20:49:09] VERBOSE[1321][C-00000005] sip/route.c: sip_route_dump: route/path hop: [Sep 1 20:49:09] DEBUG[1321][C-00000005] netsock2.c: Splitting '172.28.128.200:5060' into... [Sep 1 20:49:09] DEBUG[1321][C-00000005] netsock2.c: ...host '172.28.128.200' and port '5060'. [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Session-Expires: 1800 [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Refresher: UAC [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Strict routing enforced for session 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 [Sep 1 20:49:09] VERBOSE[1321][C-00000005] chan_sip.c: set_destination: Parsing for address/port to send to [Sep 1 20:49:09] DEBUG[1321][C-00000005] netsock2.c: Splitting '172.28.128.200:5060' into... [Sep 1 20:49:09] DEBUG[1321][C-00000005] netsock2.c: ...host '172.28.128.200' and port '5060'. [Sep 1 20:49:09] VERBOSE[1321][C-00000005] chan_sip.c: set_destination: set destination to 172.28.128.200:5060 [Sep 1 20:49:09] VERBOSE[1321][C-00000005] chan_sip.c: Transmitting (no NAT) to 172.28.128.200:5060: ACK sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK24f88ff0 Max-Forwards: 70 From: "Anonymous" ;tag=as165dcdc6 To: ;tag=92cf4279 Contact: Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 CSeq: 102 ACK User-Agent: Asterisk PBX 16.8.0.ips Content-Length: 0 --- [Sep 1 20:49:09] DEBUG[1321][C-00000005] chan_sip.c: Trying to put 'ACK sip:900' onto UDP socket destined for 172.28.128.200:5060 [Sep 1 20:49:09] DEBUG[1321] chan_sip.c: Session timer started: 10 - 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 900000ms [Sep 1 20:49:09] VERBOSE[1476][C-00000005] app_dial.c: SIP/9000-00000001 answered Local/s@originate-leg2-00000002;2 [Sep 1 20:49:09] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for SIP - 9000 [Sep 1 20:49:09] DEBUG[1270] chan_sip.c: Checking device state for peer 9000 [Sep 1 20:49:09] DEBUG[1270] devicestate.c: Changing state for SIP/9000 - state 1 (Not in use) [Sep 1 20:49:09] VERBOSE[1476][C-00000005] app_stack.c: SIP/9000-00000001 Internal Gosub(orig-ans,s,1) start [Sep 1 20:49:09] DEBUG[1476][C-00000005] app_stack.c: SIP/9000-00000001 Original location: pstn-outgoing,,1 [Sep 1 20:49:09] DEBUG[1476][C-00000005] app_stack.c: Channel SIP/9000-00000001 has no datastore, so we're allocating one. [Sep 1 20:49:09] DEBUG[1476][C-00000005] app_stack.c: Gosub exited with status 0 [Sep 1 20:49:09] DEBUG[1476][C-00000005] pbx_variables.c: Result of 'CHANNEL' is 'SIP/9000-00000001' [Sep 1 20:49:09] DEBUG[1476][C-00000005] pbx.c: Launching 'Set' [Sep 1 20:49:09] VERBOSE[1476][C-00000005] pbx.c: Executing [s@orig-ans:1] Set("SIP/9000-00000001", "DB(test/chan)=SIP/9000-00000001") in new stack [Sep 1 20:49:09] DEBUG[1476][C-00000005] pbx.c: Launching 'Return' [Sep 1 20:49:09] VERBOSE[1476][C-00000005] pbx.c: Executing [s@orig-ans:2] Return("SIP/9000-00000001", "") in new stack [Sep 1 20:49:09] DEBUG[1476][C-00000005] app_stack.c: Spawn extension (pstn-outgoing,,1) exited with -1 on 'SIP/9000-00000001' [Sep 1 20:49:09] VERBOSE[1476][C-00000005] app_stack.c: Spawn extension (pstn-outgoing, , 1) exited non-zero on 'SIP/9000-00000001' [Sep 1 20:49:09] VERBOSE[1476][C-00000005] app_stack.c: SIP/9000-00000001 Internal Gosub(orig-ans,s,1) complete GOSUB_RETVAL= [Sep 1 20:49:09] DEBUG[1476][C-00000005] app_stack.c: SIP/9000-00000001 Ending location: pstn-outgoing,,1 [Sep 1 20:49:09] DEBUG[1476][C-00000005] channel.c: Channel Local/s@originate-leg2-00000002;2 setting write format path: slin -> slin [Sep 1 20:49:09] DEBUG[1476][C-00000005] channel.c: Channel Local/s@originate-leg2-00000002;2 setting read format path: slin -> slin [Sep 1 20:49:09] DEBUG[1476][C-00000005] core_unreal.c: Blocked indication -1 [Sep 1 20:49:09] DEBUG[1476][C-00000005] stasis.c: Creating topic. name: bridge:81b6278c-7790-436f-b5dd-8672773fd26b, detail: [Sep 1 20:49:09] DEBUG[1476][C-00000005] stasis.c: Topic 'bridge:81b6278c-7790-436f-b5dd-8672773fd26b': 0x555896d1b190 created [Sep 1 20:49:09] DEBUG[1476][C-00000005] stasis.c: Creating topic. name: cache:33/bridge:81b6278c-7790-436f-b5dd-8672773fd26b, detail: [Sep 1 20:49:09] DEBUG[1476][C-00000005] stasis.c: Topic 'cache:33/bridge:81b6278c-7790-436f-b5dd-8672773fd26b': 0x555896c57d40 created [Sep 1 20:49:09] VERBOSE[1475] dial.c: Local/s@originate-leg2-00000002;1 answered [Sep 1 20:49:09] DEBUG[1475][C-00000006] pbx_variables.c: Result of 'CONTEXT' is 'originate-leg1' [Sep 1 20:49:09] DEBUG[1475][C-00000006] pbx.c: Launching 'NoOp' [Sep 1 20:49:09] VERBOSE[1475][C-00000006] pbx.c: Executing [s@originate-leg1:1] NoOp("Local/s@originate-leg2-00000002;1", "originate-leg1") in new stack [Sep 1 20:49:09] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for Local - s@originate-leg2 [Sep 1 20:49:09] DEBUG[1270] devicestate.c: Changing state for Local/s@originate-leg2 - state 2 (In use) [Sep 1 20:49:09] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for Local - s@originate-leg2 [Sep 1 20:49:09] DEBUG[1270] devicestate.c: Changing state for Local/s@originate-leg2 - state 2 (In use) [Sep 1 20:49:09] DEBUG[1339] app_queue.c: Device 'Local/s@originate-leg2' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 1 20:49:09] DEBUG[1339] app_queue.c: Device 'Local/s@originate-leg2' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge_native_rtp.c: Bridge '81b6278c-7790-436f-b5dd-8672773fd26b' can not use native RTP bridge as two channels are required [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Chose bridge technology simple_bridge [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: calling simple_bridge technology constructor [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: calling simple_bridge technology start [Sep 1 20:49:09] DEBUG[1475][C-00000006] pbx_variables.c: Function DB(test/chan) result is 'SIP/9000-00000001' [Sep 1 20:49:09] DEBUG[1475][C-00000006] pbx.c: Launching 'ChannelRedirect' [Sep 1 20:49:09] VERBOSE[1475][C-00000006] pbx.c: Executing [s@originate-leg1:2] ChannelRedirect("Local/s@originate-leg2-00000002;1", "SIP/9000-00000001,bridgewait-forever,s,1") in new stack [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge_channel.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: 0x147de809cb20(SIP/9000-00000001) is joining [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge_channel.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: pushing 0x147de809cb20(SIP/9000-00000001) [Sep 1 20:49:09] VERBOSE[1477][C-00000005] bridge_channel.c: Channel SIP/9000-00000001 joined 'simple_bridge' basic-bridge <81b6278c-7790-436f-b5dd-8672773fd26b> [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge_native_rtp.c: Bridge '81b6278c-7790-436f-b5dd-8672773fd26b' can not use native RTP bridge as two channels are required [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge technology softmix does not have any capabilities we want. [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Chose bridge technology simple_bridge [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b is already using the new technology. [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: 0x147de809cb20(SIP/9000-00000001) is joining simple_bridge technology [Sep 1 20:49:09] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Changing ssrc from 87586724 to 924520323 due to a source change [Sep 1 20:49:09] VERBOSE[1477][C-00000005] res_rtp_asterisk.c: 0x147de8019d50 -- Strict RTP switching to RTP target address 172.28.128.200:8000 as source [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge_channel.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: 0x147de809cfc0(Local/s@originate-leg2-00000002;2) is joining [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge_channel.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: pushing 0x147de809cfc0(Local/s@originate-leg2-00000002;2) [Sep 1 20:49:09] VERBOSE[1476][C-00000005] bridge_channel.c: Channel Local/s@originate-leg2-00000002;2 joined 'simple_bridge' basic-bridge <81b6278c-7790-436f-b5dd-8672773fd26b> [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge_native_rtp.c: Bridge '81b6278c-7790-436f-b5dd-8672773fd26b'. Checking compatability for channels 'SIP/9000-00000001' and 'Local/s@originate-leg2-00000002;2' [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge_native_rtp.c: Bridge '81b6278c-7790-436f-b5dd-8672773fd26b' can not use native RTP bridge as could not get details [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge technology softmix does not have any capabilities we want. [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Chose bridge technology simple_bridge [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b is already using the new technology. [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: 0x147de809cfc0(Local/s@originate-leg2-00000002;2) is joining simple_bridge technology [Sep 1 20:49:09] DEBUG[1476][C-00000005] channel.c: Channel Local/s@originate-leg2-00000002;2 setting read format path: slin -> slin [Sep 1 20:49:09] DEBUG[1476][C-00000005] channel.c: Channel Local/s@originate-leg2-00000002;2 setting write format path: slin -> slin [Sep 1 20:49:09] DEBUG[1475][C-00000006] channel.c: Soft-Hanging (0x02) up channel 'SIP/9000-00000001' [Sep 1 20:49:09] VERBOSE[1475][C-00000006] pbx.c: Auto fallthrough, channel 'Local/s@originate-leg2-00000002;1' status is 'UNKNOWN' [Sep 1 20:49:09] DEBUG[1475][C-00000006] channel.c: Soft-Hanging (0x10) up channel 'Local/s@originate-leg2-00000002;1' [Sep 1 20:49:09] DEBUG[1475][C-00000006] channel.c: Channel 0x147de405b460 'Local/s@originate-leg2-00000002;1' hanging up. Refs: 2 [Sep 1 20:49:09] DEBUG[1475][C-00000006] channel.c: Channel 0x147de405b460 'Local/s@originate-leg2-00000002;1' destroying [Sep 1 20:49:09] DEBUG[1475][C-00000006] stasis.c: Destroying topic. name: cache:30/channel:1599007747.11, detail: [Sep 1 20:49:09] DEBUG[1475][C-00000006] stasis.c: Topic 'cache:30/channel:1599007747.11': 0x147de40408e0 destroyed [Sep 1 20:49:09] DEBUG[1475][C-00000006] stasis.c: Destroying topic. name: channel:1599007747.11, detail: [Sep 1 20:49:09] DEBUG[1475][C-00000006] stasis.c: Topic 'channel:1599007747.11': 0x555896d235b0 destroyed [Sep 1 20:49:09] DEBUG[1278] cdr.c: Finalized CDR for SIP/9000-00000001 - start 1599007747.942416 answer 1599007749.931189 end 1599007749.958553 dur 2.016 bill 0.027 dispo ANSWERED [Sep 1 20:49:09] DEBUG[1278] cdr.c: Finalized CDR for Local/s@originate-leg2-00000002;1 - start 1599007747.926100 answer 1599007749.942284 end 1599007749.959856 dur 2.033 bill 0.017 dispo ANSWERED [Sep 1 20:49:09] DEBUG[1278] stasis.c: Creating topic. name: channel:1599007749.14, detail: [Sep 1 20:49:09] DEBUG[1278] stasis.c: Topic 'channel:1599007749.14': 0x147de4107ea0 created [Sep 1 20:49:09] DEBUG[1278] stasis.c: Creating topic. name: cache:34/channel:1599007749.14, detail: [Sep 1 20:49:09] DEBUG[1278] stasis.c: Topic 'cache:34/channel:1599007749.14': 0x555896f0f490 created [Sep 1 20:49:09] DEBUG[1278] stasis.c: Destroying topic. name: cache:34/channel:1599007749.14, detail: [Sep 1 20:49:09] DEBUG[1278] stasis.c: Topic 'cache:34/channel:1599007749.14': 0x555896f0f490 destroyed [Sep 1 20:49:09] DEBUG[1278] stasis.c: Destroying topic. name: channel:1599007749.14, detail: [Sep 1 20:49:09] DEBUG[1278] stasis.c: Topic 'channel:1599007749.14': 0x147de4107ea0 destroyed [Sep 1 20:49:09] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for Local - s@originate-leg2 [Sep 1 20:49:09] DEBUG[1270] devicestate.c: Changing state for Local/s@originate-leg2 - state 1 (Not in use) [Sep 1 20:49:09] DEBUG[1339] app_queue.c: Device 'Local/s@originate-leg2' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge_channel.c: Setting 0x147de809cfc0(Local/s@originate-leg2-00000002;2) state from:0 to:1 [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge_channel.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: pulling 0x147de809cfc0(Local/s@originate-leg2-00000002;2) [Sep 1 20:49:09] VERBOSE[1476][C-00000005] bridge_channel.c: Channel Local/s@originate-leg2-00000002;2 left 'simple_bridge' basic-bridge <81b6278c-7790-436f-b5dd-8672773fd26b> [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge_channel.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: 0x147de809cfc0(Local/s@originate-leg2-00000002;2) is leaving simple_bridge technology [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: dissolving bridge with cause 16(Normal Clearing) [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge_channel.c: Setting 0x147de809cb20(SIP/9000-00000001) state from:0 to:2 [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: queueing action type:13 sub:1001 [Sep 1 20:49:09] DEBUG[1476][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b is dissolved, not performing smart bridge operation. [Sep 1 20:49:09] DEBUG[1476][C-00000005] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Sep 1 20:49:09] DEBUG[1476][C-00000005] pbx.c: Spawn extension (originate-leg2,s,1) exited non-zero on 'Local/s@originate-leg2-00000002;2' [Sep 1 20:49:09] VERBOSE[1476][C-00000005] pbx.c: Spawn extension (originate-leg2, s, 1) exited non-zero on 'Local/s@originate-leg2-00000002;2' [Sep 1 20:49:09] DEBUG[1476][C-00000005] channel.c: Soft-Hanging (0x10) up channel 'Local/s@originate-leg2-00000002;2' [Sep 1 20:49:09] DEBUG[1476][C-00000005] channel.c: Channel 0x147de405d120 'Local/s@originate-leg2-00000002;2' hanging up. Refs: 2 [Sep 1 20:49:09] DEBUG[1476][C-00000005] channel.c: Channel 0x147de405d120 'Local/s@originate-leg2-00000002;2' destroying [Sep 1 20:49:09] DEBUG[1476][C-00000005] stasis.c: Destroying topic. name: cache:31/channel:1599007747.12, detail: [Sep 1 20:49:09] DEBUG[1476][C-00000005] stasis.c: Topic 'cache:31/channel:1599007747.12': 0x147de4091800 destroyed [Sep 1 20:49:09] DEBUG[1476][C-00000005] stasis.c: Destroying topic. name: channel:1599007747.12, detail: [Sep 1 20:49:09] DEBUG[1476][C-00000005] stasis.c: Topic 'channel:1599007747.12': 0x147de4092a70 destroyed [Sep 1 20:49:09] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for Local - s@originate-leg2 [Sep 1 20:49:09] DEBUG[1270] core_local.c: Checking if extension s@originate-leg2 exists (devicestate) [Sep 1 20:49:09] DEBUG[1270] devicestate.c: Changing state for Local/s@originate-leg2 - state 1 (Not in use) [Sep 1 20:49:09] DEBUG[1339] app_queue.c: Device 'Local/s@originate-leg2' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 1 20:49:09] DEBUG[1278] cdr.c: Finalized CDR for Local/s@originate-leg2-00000002;2 - start 1599007747.926382 answer 1599007749.942149 end 1599007749.960901 dur 2.034 bill 0.018 dispo ANSWERED [Sep 1 20:49:09] DEBUG[1278] stasis.c: Creating topic. name: channel:1599007749.15, detail: [Sep 1 20:49:09] DEBUG[1278] stasis.c: Topic 'channel:1599007749.15': 0x147de40bd080 created [Sep 1 20:49:09] DEBUG[1278] stasis.c: Creating topic. name: cache:35/channel:1599007749.15, detail: [Sep 1 20:49:09] DEBUG[1278] stasis.c: Topic 'cache:35/channel:1599007749.15': 0x147de41086a0 created [Sep 1 20:49:09] DEBUG[1278] stasis.c: Destroying topic. name: cache:35/channel:1599007749.15, detail: [Sep 1 20:49:09] DEBUG[1278] stasis.c: Topic 'cache:35/channel:1599007749.15': 0x147de41086a0 destroyed [Sep 1 20:49:09] DEBUG[1278] stasis.c: Destroying topic. name: channel:1599007749.15, detail: [Sep 1 20:49:09] DEBUG[1278] stasis.c: Topic 'channel:1599007749.15': 0x147de40bd080 destroyed [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge_channel.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: pulling 0x147de809cb20(SIP/9000-00000001) [Sep 1 20:49:09] VERBOSE[1477][C-00000005] bridge_channel.c: Channel SIP/9000-00000001 left 'simple_bridge' basic-bridge <81b6278c-7790-436f-b5dd-8672773fd26b> [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge_channel.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: 0x147de809cb20(SIP/9000-00000001) is leaving simple_bridge technology [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge_channel.c: Channel SIP/9000-00000001 will survive this bridge; clearing outgoing (dialed) flag [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b is dissolved, not performing smart bridge operation. [Sep 1 20:49:09] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Changing ssrc from 924520323 to 938850663 due to a source change [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: actually destroying basic bridge, nobody wants it anymore [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: calling basic bridge destructor [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: calling simple_bridge technology stop [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge 81b6278c-7790-436f-b5dd-8672773fd26b: calling simple_bridge technology destructor [Sep 1 20:49:09] DEBUG[1477][C-00000005] stasis.c: Destroying topic. name: cache:33/bridge:81b6278c-7790-436f-b5dd-8672773fd26b, detail: [Sep 1 20:49:09] DEBUG[1477][C-00000005] stasis.c: Topic 'cache:33/bridge:81b6278c-7790-436f-b5dd-8672773fd26b': 0x555896c57d40 destroyed [Sep 1 20:49:09] DEBUG[1477][C-00000005] stasis.c: Destroying topic. name: bridge:81b6278c-7790-436f-b5dd-8672773fd26b, detail: [Sep 1 20:49:09] DEBUG[1477][C-00000005] stasis.c: Topic 'bridge:81b6278c-7790-436f-b5dd-8672773fd26b': 0x555896d1b190 destroyed [Sep 1 20:49:09] DEBUG[1477][C-00000005] pbx.c: Launching 'BridgeWait' [Sep 1 20:49:09] VERBOSE[1477][C-00000005] pbx.c: Executing [s@bridgewait-forever:1] BridgeWait("SIP/9000-00000001", "1,,e(n)") in new stack [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge_roles.c: Set role 'holding_participant' [Sep 1 20:49:09] DEBUG[1477][C-00000005] stasis.c: Creating topic. name: bridge:4109652d-a049-4593-a700-c5e81cbcc1d0, detail: [Sep 1 20:49:09] DEBUG[1477][C-00000005] stasis.c: Topic 'bridge:4109652d-a049-4593-a700-c5e81cbcc1d0': 0x147de400cf50 created [Sep 1 20:49:09] DEBUG[1477][C-00000005] stasis.c: Creating topic. name: cache:36/bridge:4109652d-a049-4593-a700-c5e81cbcc1d0, detail: [Sep 1 20:49:09] DEBUG[1477][C-00000005] stasis.c: Topic 'cache:36/bridge:4109652d-a049-4593-a700-c5e81cbcc1d0': 0x147de4048ba0 created [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge technology native_rtp does not have any capabilities we want. [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge technology simple_bridge does not have any capabilities we want. [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge technology softmix does not have any capabilities we want. [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Chose bridge technology holding_bridge [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: calling holding_bridge technology constructor [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: calling holding_bridge technology start [Sep 1 20:49:09] VERBOSE[1477][C-00000005] app_bridgewait.c: SIP/9000-00000001 is entering waiting bridge 1:4109652d-a049-4593-a700-c5e81cbcc1d0 [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge_channel.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: 0x147de4038eb0(SIP/9000-00000001) is joining [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge_channel.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: pushing 0x147de4038eb0(SIP/9000-00000001) [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge_roles.c: Set role 'holding_participant' [Sep 1 20:49:09] VERBOSE[1477][C-00000005] bridge_channel.c: Channel SIP/9000-00000001 joined 'holding_bridge' base-bridge <4109652d-a049-4593-a700-c5e81cbcc1d0> [Sep 1 20:49:09] DEBUG[1477][C-00000005] bridge.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: 0x147de4038eb0(SIP/9000-00000001) is joining holding_bridge technology [Sep 1 20:49:09] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Changing ssrc from 938850663 to 109635185 due to a source change [Sep 1 20:49:12] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:49:14] VERBOSE[1477][C-00000005] res_rtp_asterisk.c: 0x147de8019d50 -- Strict RTP learning complete - Locking on source address 172.28.128.200:8000 [Sep 1 20:49:16] DEBUG[1459] stasis.c: Creating topic. name: channel:1599007756.16, detail: [Sep 1 20:49:16] DEBUG[1459] stasis.c: Topic 'channel:1599007756.16': 0x555896cd67c0 created [Sep 1 20:49:16] DEBUG[1459] stasis.c: Creating topic. name: cache:37/channel:1599007756.16, detail: [Sep 1 20:49:16] DEBUG[1459] stasis.c: Topic 'cache:37/channel:1599007756.16': 0x555896d78090 created [Sep 1 20:49:16] DEBUG[1459] channel.c: Channel 0x147de4031550 'Local/s@originate-to-moh-00000003;1' allocated [Sep 1 20:49:16] DEBUG[1459] stasis.c: Creating topic. name: channel:1599007756.17, detail: [Sep 1 20:49:16] DEBUG[1459] stasis.c: Topic 'channel:1599007756.17': 0x147de41379b0 created [Sep 1 20:49:16] DEBUG[1459] stasis.c: Creating topic. name: cache:38/channel:1599007756.17, detail: [Sep 1 20:49:16] DEBUG[1459] stasis.c: Topic 'cache:38/channel:1599007756.17': 0x147de40e4190 created [Sep 1 20:49:16] DEBUG[1459] channel.c: Channel 0x147de4030550 'Local/s@originate-to-moh-00000003;2' allocated [Sep 1 20:49:16] VERBOSE[1478] dial.c: Called s@originate-to-moh [Sep 1 20:49:16] DEBUG[1479][C-00000007] pbx.c: Launching 'Answer' [Sep 1 20:49:16] VERBOSE[1479][C-00000007] pbx.c: Executing [s@originate-to-moh:1] Answer("Local/s@originate-to-moh-00000003;2", "") in new stack [Sep 1 20:49:16] DEBUG[1479][C-00000007] core_unreal.c: Blocked indication -1 [Sep 1 20:49:16] VERBOSE[1478] dial.c: Local/s@originate-to-moh-00000003;1 answered [Sep 1 20:49:16] DEBUG[1478][C-00000008] pbx.c: Launching 'Wait' [Sep 1 20:49:16] VERBOSE[1478][C-00000008] pbx.c: Executing [s@bridge-to-moh:1] Wait("Local/s@originate-to-moh-00000003;1", "0.1") in new stack [Sep 1 20:49:16] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for Local - s@originate-to-moh [Sep 1 20:49:16] DEBUG[1270] devicestate.c: Changing state for Local/s@originate-to-moh - state 2 (In use) [Sep 1 20:49:16] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for Local - s@originate-to-moh [Sep 1 20:49:16] DEBUG[1270] devicestate.c: Changing state for Local/s@originate-to-moh - state 2 (In use) [Sep 1 20:49:16] DEBUG[1339] app_queue.c: Device 'Local/s@originate-to-moh' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 1 20:49:16] DEBUG[1339] app_queue.c: Device 'Local/s@originate-to-moh' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Sep 1 20:49:17] DEBUG[1478][C-00000008] pbx_variables.c: Function DB(test/chan) result is 'SIP/9000-00000001' [Sep 1 20:49:17] DEBUG[1478][C-00000008] pbx.c: Launching 'Bridge' [Sep 1 20:49:17] VERBOSE[1478][C-00000008] pbx.c: Executing [s@bridge-to-moh:2] Bridge("Local/s@originate-to-moh-00000003;1", "SIP/9000-00000001,p") in new stack [Sep 1 20:49:17] DEBUG[1478][C-00000008] stasis.c: Creating topic. name: bridge:23a86402-0599-48f5-b7af-162de21f3a9f, detail: [Sep 1 20:49:17] DEBUG[1478][C-00000008] stasis.c: Topic 'bridge:23a86402-0599-48f5-b7af-162de21f3a9f': 0x147df002a050 created [Sep 1 20:49:17] DEBUG[1478][C-00000008] stasis.c: Creating topic. name: cache:39/bridge:23a86402-0599-48f5-b7af-162de21f3a9f, detail: [Sep 1 20:49:17] DEBUG[1478][C-00000008] stasis.c: Topic 'cache:39/bridge:23a86402-0599-48f5-b7af-162de21f3a9f': 0x147df002b170 created [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge_native_rtp.c: Bridge '23a86402-0599-48f5-b7af-162de21f3a9f' can not use native RTP bridge as two channels are required [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Chose bridge technology simple_bridge [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: calling simple_bridge technology constructor [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: calling simple_bridge technology start [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Moving 0x147de4038eb0(SIP/9000-00000001) into bridge 23a86402-0599-48f5-b7af-162de21f3a9f [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge_channel.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: pulling 0x147de4038eb0(SIP/9000-00000001) [Sep 1 20:49:17] VERBOSE[1478][C-00000008] bridge_channel.c: Channel SIP/9000-00000001 left 'holding_bridge' base-bridge <4109652d-a049-4593-a700-c5e81cbcc1d0> [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge_channel.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: 0x147de4038eb0(SIP/9000-00000001) is leaving holding_bridge technology [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge_channel.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: pushing 0x147de4038eb0(SIP/9000-00000001) [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge_roles.c: Set role 'holding_participant' [Sep 1 20:49:17] VERBOSE[1478][C-00000008] bridge_channel.c: Channel SIP/9000-00000001 joined 'simple_bridge' basic-bridge <23a86402-0599-48f5-b7af-162de21f3a9f> [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge_native_rtp.c: Bridge '23a86402-0599-48f5-b7af-162de21f3a9f' can not use native RTP bridge as two channels are required [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want. [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Chose bridge technology simple_bridge [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f is already using the new technology. [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: 0x147de4038eb0(SIP/9000-00000001) is joining simple_bridge technology [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge_channel.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: 0x147df00395c0(Local/s@originate-to-moh-00000003;1) is joining [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge_channel.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: pushing 0x147df00395c0(Local/s@originate-to-moh-00000003;1) [Sep 1 20:49:17] VERBOSE[1478][C-00000008] bridge_channel.c: Channel Local/s@originate-to-moh-00000003;1 joined 'simple_bridge' basic-bridge <23a86402-0599-48f5-b7af-162de21f3a9f> [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge_native_rtp.c: Bridge '23a86402-0599-48f5-b7af-162de21f3a9f'. Checking compatability for channels 'SIP/9000-00000001' and 'Local/s@originate-to-moh-00000003;1' [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge_native_rtp.c: Bridge '23a86402-0599-48f5-b7af-162de21f3a9f' can not use native RTP bridge as could not get details [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want. [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Chose bridge technology simple_bridge [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f is already using the new technology. [Sep 1 20:49:17] DEBUG[1478][C-00000008] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: 0x147df00395c0(Local/s@originate-to-moh-00000003;1) is joining simple_bridge technology [Sep 1 20:49:17] DEBUG[1478][C-00000008] channel.c: Channel Local/s@originate-to-moh-00000003;1 setting read format path: slin -> slin [Sep 1 20:49:17] DEBUG[1478][C-00000008] channel.c: Channel Local/s@originate-to-moh-00000003;1 setting write format path: slin -> slin [Sep 1 20:49:17] DEBUG[1278] cdr.c: Finalized CDR for Local/s@originate-to-moh-00000003;1 - start 1599007756.908281 answer 1599007756.912367 end 1599007757.016467 dur 0.108 bill 0.104 dispo ANSWERED [Sep 1 20:49:17] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 1 20:49:17] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Ooh, format changed from none to alaw [Sep 1 20:49:17] DEBUG[1477][C-00000005] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 1 20:49:17] VERBOSE[1477][C-00000005] file.c: Playing 'beep.slin' (language 'en') [Sep 1 20:49:17] DEBUG[1479][C-00000007] channel.c: Didn't receive a media frame from Local/s@originate-to-moh-00000003;2 within 500 ms of answering. Continuing anyway [Sep 1 20:49:17] DEBUG[1479][C-00000007] pbx.c: Launching 'MusicOnHold' [Sep 1 20:49:17] VERBOSE[1479][C-00000007] pbx.c: Executing [s@originate-to-moh:2] MusicOnHold("Local/s@originate-to-moh-00000003;2", "native-random") in new stack [Sep 1 20:49:17] VERBOSE[1479][C-00000007] res_musiconhold.c: Started music on hold, class 'native-random', on channel 'Local/s@originate-to-moh-00000003;2' [Sep 1 20:49:17] DEBUG[1479][C-00000007] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 1 20:49:17] DEBUG[1479][C-00000007] channel.c: Channel Local/s@originate-to-moh-00000003;2 setting write format path: slin -> slin [Sep 1 20:49:17] DEBUG[1479][C-00000007] res_musiconhold.c: Local/s@originate-to-moh-00000003;2 Opened file 0 '/var/lib/asterisk/moh/reno_project-system' [Sep 1 20:49:17] DEBUG[1477][C-00000005] channel.c: Scheduling timer at (364 requested / 364 actual) timer ticks per second [Sep 1 20:49:17] DEBUG[1477][C-00000005] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 1 20:49:17] DEBUG[1477][C-00000005] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 1 20:49:17] DEBUG[1477][C-00000005] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 1 20:49:17] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Setting the marker bit due to a source update [Sep 1 20:49:17] DEBUG[1477][C-00000005] channel.c: SIP/9000-00000001: Dropping redundant connected line update "" <>. [Sep 1 20:49:17] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 88 bytes from 172.28.128.200:8001 [Sep 1 20:49:23] DEBUG[1462] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:49:23] DEBUG[1463] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:49:23] DEBUG[1284] threadpool.c: Destroying worker thread 17 [Sep 1 20:49:23] DEBUG[1284] threadpool.c: Destroying worker thread 18 [Sep 1 20:49:23] DEBUG[1464] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:49:23] DEBUG[1284] threadpool.c: Destroying worker thread 19 [Sep 1 20:49:23] DEBUG[1461] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:49:23] DEBUG[1284] threadpool.c: Destroying worker thread 16 [Sep 1 20:49:23] DEBUG[1460] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:49:23] DEBUG[1284] threadpool.c: Destroying worker thread 15 [Sep 1 20:49:23] DEBUG[1469] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:49:23] DEBUG[1259] threadpool.c: Destroying worker thread 24 [Sep 1 20:49:23] DEBUG[1466] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:49:23] DEBUG[1470] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:49:23] DEBUG[1467] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:49:23] DEBUG[1259] threadpool.c: Destroying worker thread 21 [Sep 1 20:49:23] DEBUG[1259] threadpool.c: Destroying worker thread 25 [Sep 1 20:49:23] DEBUG[1259] threadpool.c: Destroying worker thread 22 [Sep 1 20:49:23] DEBUG[1468] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:49:23] DEBUG[1259] threadpool.c: Destroying worker thread 23 [Sep 1 20:49:23] DEBUG[1465] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:49:23] DEBUG[1259] threadpool.c: Destroying worker thread 20 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 76f8619f1453a21e15b5f9b045f40c22@[fe80::630d:d8c5:2cd9:85b8]:5060 - OPTIONS (No RTP) [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Sep 1 20:49:23] DEBUG[1321] acl.c: For destination '172.28.128.200', our source address is '172.28.128.20'. [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: SIP call-id changed from '76f8619f1453a21e15b5f9b045f40c22@[fe80::630d:d8c5:2cd9:85b8]:5060' to '2cf9f425294fc12716e6a06b7af2206a@172.28.128.20:5060' [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Initializing initreq for method OPTIONS - callid 2cf9f425294fc12716e6a06b7af2206a@172.28.128.20:5060 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 0 [ 85]: OPTIONS sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6d5f0e56 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as351bf8e0 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 4 [ 75]: To: [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 5 [ 42]: Contact: [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 6 [ 60]: Call-ID: 2cf9f425294fc12716e6a06b7af2206a@172.28.128.20:5060 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 8 [ 35]: User-Agent: Asterisk PBX 16.8.0.ips [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 9 [ 35]: Date: Wed, 02 Sep 2020 00:49:23 GMT [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Sep 1 20:49:23] VERBOSE[1321] chan_sip.c: Reliably Transmitting (no NAT) to 172.28.128.200:5060: OPTIONS sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6d5f0e56 Max-Forwards: 70 From: "asterisk" ;tag=as351bf8e0 To: Contact: Call-ID: 2cf9f425294fc12716e6a06b7af2206a@172.28.128.20:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 16.8.0.ips Date: Wed, 02 Sep 2020 00:49:23 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #16 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.28.128.200:5060 [Sep 1 20:49:23] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6d5f0e56 Contact: To: ;tag=d2c1af56 From: "asterisk";tag=as351bf8e0 Call-ID: 2cf9f425294fc12716e6a06b7af2206a@172.28.128.20:5060 CSeq: 102 OPTIONS Accept: application/sdp, application/sdp Accept-Language: en Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri User-Agent: Z 3.3.25608 r25552 Allow-Events: presence, kpml Content-Length: 0 <-------------> [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK6d5f0e56 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 2 [ 34]: Contact: [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 3 [ 88]: To: ;tag=d2c1af56 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 4 [ 59]: From: "asterisk";tag=as351bf8e0 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 5 [ 60]: Call-ID: 2cf9f425294fc12716e6a06b7af2206a@172.28.128.20:5060 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 6 [ 17]: CSeq: 102 OPTIONS [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 7 [ 40]: Accept: application/sdp, application/sdp [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 10 [ 74]: Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 11 [ 30]: User-Agent: Z 3.3.25608 r25552 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 12 [ 28]: Allow-Events: presence, kpml [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Sep 1 20:49:23] VERBOSE[1321] chan_sip.c: --- (14 headers 0 lines) --- [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: = Looking for Call ID: 2cf9f425294fc12716e6a06b7af2206a@172.28.128.20:5060 (Checking To) --From tag as351bf8e0 --To-tag d2c1af56 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #16 [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Stopping retransmission on '2cf9f425294fc12716e6a06b7af2206a@172.28.128.20:5060' of Request 102: Match Found [Sep 1 20:49:23] DEBUG[1321] chan_sip.c: Destroying SIP dialog 2cf9f425294fc12716e6a06b7af2206a@172.28.128.20:5060 [Sep 1 20:49:23] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '2cf9f425294fc12716e6a06b7af2206a@172.28.128.20:5060' Method: OPTIONS [Sep 1 20:49:24] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 88 bytes from 172.28.128.200:8001 [Sep 1 20:49:28] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 88 bytes from 172.28.128.200:8001 [Sep 1 20:49:34] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 88 bytes from 172.28.128.200:8001 [Sep 1 20:49:34] DEBUG[1298] res_pjsip_registrar.c: Woke up at 1599007774 Interval: 30 [Sep 1 20:49:34] DEBUG[1298] res_pjsip_registrar.c: Expiring 0 contacts [Sep 1 20:49:40] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 88 bytes from 172.28.128.200:8001 [Sep 1 20:49:45] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 88 bytes from 172.28.128.200:8001 [Sep 1 20:49:50] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 88 bytes from 172.28.128.200:8001 [Sep 1 20:49:51] DEBUG[1459] channel.c: Soft-Hanging (0x02) up channel 'SIP/9000-00000001' [Sep 1 20:49:51] DEBUG[1477][C-00000005] bridge_channel.c: Setting 0x147de4038eb0(SIP/9000-00000001) state from:0 to:1 [Sep 1 20:49:51] DEBUG[1477][C-00000005] bridge_channel.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: pulling 0x147de4038eb0(SIP/9000-00000001) [Sep 1 20:49:51] VERBOSE[1477][C-00000005] bridge_channel.c: Channel SIP/9000-00000001 left 'simple_bridge' basic-bridge <23a86402-0599-48f5-b7af-162de21f3a9f> [Sep 1 20:49:51] DEBUG[1477][C-00000005] bridge_channel.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: 0x147de4038eb0(SIP/9000-00000001) is leaving simple_bridge technology [Sep 1 20:49:51] DEBUG[1477][C-00000005] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: dissolving bridge with cause 16(Normal Clearing) [Sep 1 20:49:51] DEBUG[1477][C-00000005] bridge_channel.c: Setting 0x147df00395c0(Local/s@originate-to-moh-00000003;1) state from:0 to:2 [Sep 1 20:49:51] DEBUG[1477][C-00000005] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: queueing action type:13 sub:1001 [Sep 1 20:49:51] DEBUG[1477][C-00000005] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f is dissolved, not performing smart bridge operation. [Sep 1 20:49:51] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Changing ssrc from 109635185 to 753045710 due to a source change [Sep 1 20:49:51] DEBUG[1477][C-00000005] bridge.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: telling all channels to leave the party [Sep 1 20:49:51] DEBUG[1477][C-00000005] bridge.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: dissolving bridge with cause 16(Normal Clearing) [Sep 1 20:49:51] DEBUG[1477][C-00000005] bridge.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: queueing action type:13 sub:1001 [Sep 1 20:49:51] DEBUG[1477][C-00000005] pbx.c: Spawn extension (bridgewait-loop,s,1) exited non-zero on 'SIP/9000-00000001' [Sep 1 20:49:51] VERBOSE[1477][C-00000005] pbx.c: Spawn extension (bridgewait-loop, s, 1) exited non-zero on 'SIP/9000-00000001' [Sep 1 20:49:51] DEBUG[1477][C-00000005] pbx.c: Launching 'Playback' [Sep 1 20:49:51] VERBOSE[1477][C-00000005] pbx.c: Executing [s@bridgewait-loop:1] Playback("SIP/9000-00000001", "pls-stay-on-line") in new stack [Sep 1 20:49:51] DEBUG[1477][C-00000005] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Sep 1 20:49:51] VERBOSE[1477][C-00000005] file.c: Playing 'pls-stay-on-line.slin' (language 'en') [Sep 1 20:49:51] DEBUG[1278] cdr.c: Finalized CDR for SIP/9000-00000001 - start 1599007757.015974 answer 1599007757.015974 end 1599007791.405306 dur 34.389 bill 34.389 dispo ANSWERED [Sep 1 20:49:51] DEBUG[1478][C-00000008] bridge_channel.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: pulling 0x147df00395c0(Local/s@originate-to-moh-00000003;1) [Sep 1 20:49:51] VERBOSE[1478][C-00000008] bridge_channel.c: Channel Local/s@originate-to-moh-00000003;1 left 'simple_bridge' basic-bridge <23a86402-0599-48f5-b7af-162de21f3a9f> [Sep 1 20:49:51] DEBUG[1478][C-00000008] bridge_channel.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: 0x147df00395c0(Local/s@originate-to-moh-00000003;1) is leaving simple_bridge technology [Sep 1 20:49:51] DEBUG[1478][C-00000008] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f is dissolved, not performing smart bridge operation. [Sep 1 20:49:51] VERBOSE[1478][C-00000008] pbx.c: Auto fallthrough, channel 'Local/s@originate-to-moh-00000003;1' status is 'UNKNOWN' [Sep 1 20:49:51] DEBUG[1478][C-00000008] channel.c: Soft-Hanging (0x10) up channel 'Local/s@originate-to-moh-00000003;1' [Sep 1 20:49:51] DEBUG[1478][C-00000008] channel.c: Channel 0x147de4031550 'Local/s@originate-to-moh-00000003;1' hanging up. Refs: 2 [Sep 1 20:49:51] DEBUG[1478][C-00000008] channel.c: Channel 0x147de4031550 'Local/s@originate-to-moh-00000003;1' destroying [Sep 1 20:49:51] DEBUG[1478][C-00000008] stasis.c: Destroying topic. name: cache:37/channel:1599007756.16, detail: [Sep 1 20:49:51] DEBUG[1478][C-00000008] stasis.c: Topic 'cache:37/channel:1599007756.16': 0x555896d78090 destroyed [Sep 1 20:49:51] DEBUG[1478][C-00000008] stasis.c: Destroying topic. name: channel:1599007756.16, detail: [Sep 1 20:49:51] DEBUG[1478][C-00000008] stasis.c: Topic 'channel:1599007756.16': 0x555896cd67c0 destroyed [Sep 1 20:49:51] DEBUG[1269][C-00000008] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: actually destroying basic bridge, nobody wants it anymore [Sep 1 20:49:51] DEBUG[1269][C-00000008] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: calling basic bridge destructor [Sep 1 20:49:51] DEBUG[1269][C-00000008] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: calling simple_bridge technology stop [Sep 1 20:49:51] DEBUG[1269][C-00000008] bridge.c: Bridge 23a86402-0599-48f5-b7af-162de21f3a9f: calling simple_bridge technology destructor [Sep 1 20:49:51] DEBUG[1269][C-00000008] stasis.c: Destroying topic. name: cache:39/bridge:23a86402-0599-48f5-b7af-162de21f3a9f, detail: [Sep 1 20:49:51] DEBUG[1269][C-00000008] stasis.c: Topic 'cache:39/bridge:23a86402-0599-48f5-b7af-162de21f3a9f': 0x147df002b170 destroyed [Sep 1 20:49:51] DEBUG[1269][C-00000008] stasis.c: Destroying topic. name: bridge:23a86402-0599-48f5-b7af-162de21f3a9f, detail: [Sep 1 20:49:51] DEBUG[1269][C-00000008] stasis.c: Topic 'bridge:23a86402-0599-48f5-b7af-162de21f3a9f': 0x147df002a050 destroyed [Sep 1 20:49:51] DEBUG[1269][C-00000005] bridge.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: actually destroying base bridge, nobody wants it anymore [Sep 1 20:49:51] DEBUG[1269][C-00000005] bridge.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: calling base bridge destructor [Sep 1 20:49:51] DEBUG[1269][C-00000005] bridge.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: calling holding_bridge technology stop [Sep 1 20:49:51] DEBUG[1269][C-00000005] bridge.c: Bridge 4109652d-a049-4593-a700-c5e81cbcc1d0: calling holding_bridge technology destructor [Sep 1 20:49:51] DEBUG[1269][C-00000005] stasis.c: Destroying topic. name: cache:36/bridge:4109652d-a049-4593-a700-c5e81cbcc1d0, detail: [Sep 1 20:49:51] DEBUG[1269][C-00000005] stasis.c: Topic 'cache:36/bridge:4109652d-a049-4593-a700-c5e81cbcc1d0': 0x147de4048ba0 destroyed [Sep 1 20:49:51] DEBUG[1269][C-00000005] stasis.c: Destroying topic. name: bridge:4109652d-a049-4593-a700-c5e81cbcc1d0, detail: [Sep 1 20:49:51] DEBUG[1269][C-00000005] stasis.c: Topic 'bridge:4109652d-a049-4593-a700-c5e81cbcc1d0': 0x147de400cf50 destroyed [Sep 1 20:49:51] VERBOSE[1479][C-00000007] res_musiconhold.c: Stopped music on hold on Local/s@originate-to-moh-00000003;2 [Sep 1 20:49:51] DEBUG[1479][C-00000007] channel.c: Channel Local/s@originate-to-moh-00000003;2 setting write format path: slin -> slin [Sep 1 20:49:51] DEBUG[1479][C-00000007] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 1 20:49:51] DEBUG[1479][C-00000007] pbx.c: Spawn extension (originate-to-moh,s,2) exited non-zero on 'Local/s@originate-to-moh-00000003;2' [Sep 1 20:49:51] VERBOSE[1479][C-00000007] pbx.c: Spawn extension (originate-to-moh, s, 2) exited non-zero on 'Local/s@originate-to-moh-00000003;2' [Sep 1 20:49:51] DEBUG[1479][C-00000007] channel.c: Soft-Hanging (0x10) up channel 'Local/s@originate-to-moh-00000003;2' [Sep 1 20:49:51] DEBUG[1479][C-00000007] channel.c: Channel 0x147de4030550 'Local/s@originate-to-moh-00000003;2' hanging up. Refs: 2 [Sep 1 20:49:51] DEBUG[1479][C-00000007] channel.c: Channel 0x147de4030550 'Local/s@originate-to-moh-00000003;2' destroying [Sep 1 20:49:51] DEBUG[1479][C-00000007] stasis.c: Destroying topic. name: cache:38/channel:1599007756.17, detail: [Sep 1 20:49:51] DEBUG[1479][C-00000007] stasis.c: Topic 'cache:38/channel:1599007756.17': 0x147de40e4190 destroyed [Sep 1 20:49:51] DEBUG[1479][C-00000007] stasis.c: Destroying topic. name: channel:1599007756.17, detail: [Sep 1 20:49:51] DEBUG[1479][C-00000007] stasis.c: Topic 'channel:1599007756.17': 0x147de41379b0 destroyed [Sep 1 20:49:51] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for Local - s@originate-to-moh [Sep 1 20:49:51] DEBUG[1270] core_local.c: Checking if extension s@originate-to-moh exists (devicestate) [Sep 1 20:49:51] DEBUG[1270] devicestate.c: Changing state for Local/s@originate-to-moh - state 1 (Not in use) [Sep 1 20:49:51] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for Local - s@originate-to-moh [Sep 1 20:49:51] DEBUG[1270] core_local.c: Checking if extension s@originate-to-moh exists (devicestate) [Sep 1 20:49:51] DEBUG[1270] devicestate.c: Changing state for Local/s@originate-to-moh - state 1 (Not in use) [Sep 1 20:49:51] DEBUG[1339] app_queue.c: Device 'Local/s@originate-to-moh' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 1 20:49:51] DEBUG[1339] app_queue.c: Device 'Local/s@originate-to-moh' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 1 20:49:51] DEBUG[1278] stasis.c: Creating topic. name: channel:1599007791.18, detail: [Sep 1 20:49:51] DEBUG[1278] stasis.c: Topic 'channel:1599007791.18': 0x147de4025cf0 created [Sep 1 20:49:51] DEBUG[1278] stasis.c: Creating topic. name: cache:40/channel:1599007791.18, detail: [Sep 1 20:49:51] DEBUG[1278] stasis.c: Topic 'cache:40/channel:1599007791.18': 0x147de4027320 created [Sep 1 20:49:51] DEBUG[1278] stasis.c: Destroying topic. name: cache:40/channel:1599007791.18, detail: [Sep 1 20:49:51] DEBUG[1278] stasis.c: Topic 'cache:40/channel:1599007791.18': 0x147de4027320 destroyed [Sep 1 20:49:51] DEBUG[1278] stasis.c: Destroying topic. name: channel:1599007791.18, detail: [Sep 1 20:49:51] DEBUG[1278] stasis.c: Topic 'channel:1599007791.18': 0x147de4025cf0 destroyed [Sep 1 20:49:51] DEBUG[1278] cdr.c: Finalized CDR for Local/s@originate-to-moh-00000003;2 - start 1599007756.908680 answer 1599007756.911827 end 1599007791.410399 dur 34.501 bill 34.498 dispo ANSWERED [Sep 1 20:49:51] DEBUG[1278] stasis.c: Creating topic. name: channel:1599007791.19, detail: [Sep 1 20:49:51] DEBUG[1278] stasis.c: Topic 'channel:1599007791.19': 0x147de4105650 created [Sep 1 20:49:51] DEBUG[1278] stasis.c: Creating topic. name: cache:41/channel:1599007791.19, detail: [Sep 1 20:49:51] DEBUG[1278] stasis.c: Topic 'cache:41/channel:1599007791.19': 0x147dec015db0 created [Sep 1 20:49:51] DEBUG[1278] stasis.c: Destroying topic. name: cache:41/channel:1599007791.19, detail: [Sep 1 20:49:51] DEBUG[1278] stasis.c: Topic 'cache:41/channel:1599007791.19': 0x147dec015db0 destroyed [Sep 1 20:49:51] DEBUG[1278] stasis.c: Destroying topic. name: channel:1599007791.19, detail: [Sep 1 20:49:51] DEBUG[1278] stasis.c: Topic 'channel:1599007791.19': 0x147de4105650 destroyed [Sep 1 20:49:56] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 112 bytes from 172.28.128.200:8001 [Sep 1 20:49:56] DEBUG[1477][C-00000005] channel.c: Scheduling timer at (58 requested / 58 actual) timer ticks per second [Sep 1 20:49:56] DEBUG[1477][C-00000005] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 1 20:49:56] DEBUG[1477][C-00000005] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 1 20:49:56] DEBUG[1477][C-00000005] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Sep 1 20:49:56] DEBUG[1477][C-00000005] pbx.c: Launching 'BridgeWait' [Sep 1 20:49:56] VERBOSE[1477][C-00000005] pbx.c: Executing [s@bridgewait-loop:2] BridgeWait("SIP/9000-00000001", "1,,e(n)S(10)") in new stack [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge.c: Putting interval hook 0x147de4062bd8 with interval 10000 in the heap on features 0x147dfafdd8c0 [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge_roles.c: Bridge role holding_participant is already applied to the channel SIP/9000-00000001 [Sep 1 20:49:56] DEBUG[1477][C-00000005] stasis.c: Creating topic. name: bridge:d3bb2634-1b0a-4932-a678-cbaa600796cf, detail: [Sep 1 20:49:56] DEBUG[1477][C-00000005] stasis.c: Topic 'bridge:d3bb2634-1b0a-4932-a678-cbaa600796cf': 0x147de41099a0 created [Sep 1 20:49:56] DEBUG[1477][C-00000005] stasis.c: Creating topic. name: cache:42/bridge:d3bb2634-1b0a-4932-a678-cbaa600796cf, detail: [Sep 1 20:49:56] DEBUG[1477][C-00000005] stasis.c: Topic 'cache:42/bridge:d3bb2634-1b0a-4932-a678-cbaa600796cf': 0x147de4091800 created [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge.c: Bridge technology native_rtp does not have any capabilities we want. [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge.c: Bridge technology simple_bridge does not have any capabilities we want. [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge.c: Bridge technology softmix does not have any capabilities we want. [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge.c: Chose bridge technology holding_bridge [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: calling holding_bridge technology constructor [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: calling holding_bridge technology start [Sep 1 20:49:56] VERBOSE[1477][C-00000005] app_bridgewait.c: SIP/9000-00000001 is entering waiting bridge 1:d3bb2634-1b0a-4932-a678-cbaa600796cf [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge_channel.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: 0x147de40b6170(SIP/9000-00000001) is joining [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge_channel.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: pushing 0x147de40b6170(SIP/9000-00000001) [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge_roles.c: Set role 'holding_participant' [Sep 1 20:49:56] VERBOSE[1477][C-00000005] bridge_channel.c: Channel SIP/9000-00000001 joined 'holding_bridge' base-bridge [Sep 1 20:49:56] DEBUG[1477][C-00000005] bridge.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: 0x147de40b6170(SIP/9000-00000001) is joining holding_bridge technology [Sep 1 20:49:56] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Changing ssrc from 753045710 to 96279916 due to a source change [Sep 1 20:50:01] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 88 bytes from 172.28.128.200:8001 [Sep 1 20:50:04] DEBUG[1298] res_pjsip_registrar.c: Woke up at 1599007804 Interval: 30 [Sep 1 20:50:04] DEBUG[1298] res_pjsip_registrar.c: Expiring 0 contacts [Sep 1 20:50:05] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:50:06] DEBUG[1477][C-00000005] bridge_channel.c: Executing hook 0x147de4062bd8 on 0x147de40b6170(SIP/9000-00000001) [Sep 1 20:50:06] VERBOSE[1477][C-00000005] app_bridgewait.c: Channel SIP/9000-00000001 timed out. [Sep 1 20:50:06] DEBUG[1477][C-00000005] bridge_channel.c: Setting 0x147de40b6170(SIP/9000-00000001) state from:0 to:1 [Sep 1 20:50:06] DEBUG[1477][C-00000005] bridge_channel.c: Removed interval hook 0x147de4062bd8 from 0x147de40b6170(SIP/9000-00000001) [Sep 1 20:50:06] DEBUG[1477][C-00000005] bridge_channel.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: pulling 0x147de40b6170(SIP/9000-00000001) [Sep 1 20:50:06] VERBOSE[1477][C-00000005] bridge_channel.c: Channel SIP/9000-00000001 left 'holding_bridge' base-bridge [Sep 1 20:50:06] DEBUG[1477][C-00000005] bridge_channel.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: 0x147de40b6170(SIP/9000-00000001) is leaving holding_bridge technology [Sep 1 20:50:06] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Changing ssrc from 96279916 to 73488658 due to a source change [Sep 1 20:50:06] DEBUG[1477][C-00000005] bridge_after.c: Setup after bridge goto location to bridgewait-forever,s,2. [Sep 1 20:50:06] DEBUG[1477][C-00000005] channel.c: Soft-Hanging (0x02) up channel 'SIP/9000-00000001' [Sep 1 20:50:06] DEBUG[1477][C-00000005] bridge.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: telling all channels to leave the party [Sep 1 20:50:06] DEBUG[1477][C-00000005] bridge.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: dissolving bridge with cause 16(Normal Clearing) [Sep 1 20:50:06] DEBUG[1477][C-00000005] bridge.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: queueing action type:13 sub:1001 [Sep 1 20:50:06] DEBUG[1477][C-00000005] pbx.c: Spawn extension (bridgewait-forever,s,2) exited non-zero on 'SIP/9000-00000001' [Sep 1 20:50:06] VERBOSE[1477][C-00000005] pbx.c: Spawn extension (bridgewait-forever, s, 2) exited non-zero on 'SIP/9000-00000001' [Sep 1 20:50:06] DEBUG[1477][C-00000005] pbx.c: Launching 'NoOp' [Sep 1 20:50:06] VERBOSE[1477][C-00000005] pbx.c: Executing [s@bridgewait-forever:2] NoOp("SIP/9000-00000001", "This should not happen") in new stack [Sep 1 20:50:06] DEBUG[1477][C-00000005] pbx.c: Launching 'Wait' [Sep 1 20:50:06] VERBOSE[1477][C-00000005] pbx.c: Executing [s@bridgewait-forever:3] Wait("SIP/9000-00000001", "120") in new stack [Sep 1 20:50:06] DEBUG[1269][C-00000005] bridge.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: actually destroying base bridge, nobody wants it anymore [Sep 1 20:50:06] DEBUG[1269][C-00000005] bridge.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: calling base bridge destructor [Sep 1 20:50:06] DEBUG[1269][C-00000005] bridge.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: calling holding_bridge technology stop [Sep 1 20:50:06] DEBUG[1269][C-00000005] bridge.c: Bridge d3bb2634-1b0a-4932-a678-cbaa600796cf: calling holding_bridge technology destructor [Sep 1 20:50:06] DEBUG[1269][C-00000005] stasis.c: Destroying topic. name: cache:42/bridge:d3bb2634-1b0a-4932-a678-cbaa600796cf, detail: [Sep 1 20:50:06] DEBUG[1269][C-00000005] stasis.c: Topic 'cache:42/bridge:d3bb2634-1b0a-4932-a678-cbaa600796cf': 0x147de4091800 destroyed [Sep 1 20:50:06] DEBUG[1269][C-00000005] stasis.c: Destroying topic. name: bridge:d3bb2634-1b0a-4932-a678-cbaa600796cf, detail: [Sep 1 20:50:06] DEBUG[1269][C-00000005] stasis.c: Topic 'bridge:d3bb2634-1b0a-4932-a678-cbaa600796cf': 0x147de41099a0 destroyed [Sep 1 20:50:08] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:50:13] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:50:19] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 6b01df5267c3b35c6f5fd6642407510a@[fe80::630d:d8c5:2cd9:85b8]:5060 - OPTIONS (No RTP) [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Sep 1 20:50:23] DEBUG[1321] acl.c: For destination '172.28.128.200', our source address is '172.28.128.20'. [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: SIP call-id changed from '6b01df5267c3b35c6f5fd6642407510a@[fe80::630d:d8c5:2cd9:85b8]:5060' to '3e537f011fbac93f361badc26f148c95@172.28.128.20:5060' [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Initializing initreq for method OPTIONS - callid 3e537f011fbac93f361badc26f148c95@172.28.128.20:5060 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 0 [ 85]: OPTIONS sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK7230e8b8 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as5c124d20 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 4 [ 75]: To: [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 5 [ 42]: Contact: [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 6 [ 60]: Call-ID: 3e537f011fbac93f361badc26f148c95@172.28.128.20:5060 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 8 [ 35]: User-Agent: Asterisk PBX 16.8.0.ips [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 9 [ 35]: Date: Wed, 02 Sep 2020 00:50:23 GMT [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Sep 1 20:50:23] VERBOSE[1321] chan_sip.c: Reliably Transmitting (no NAT) to 172.28.128.200:5060: OPTIONS sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK7230e8b8 Max-Forwards: 70 From: "asterisk" ;tag=as5c124d20 To: Contact: Call-ID: 3e537f011fbac93f361badc26f148c95@172.28.128.20:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 16.8.0.ips Date: Wed, 02 Sep 2020 00:50:23 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #5 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.28.128.200:5060 [Sep 1 20:50:23] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK7230e8b8 Contact: To: ;tag=cc930138 From: "asterisk";tag=as5c124d20 Call-ID: 3e537f011fbac93f361badc26f148c95@172.28.128.20:5060 CSeq: 102 OPTIONS Accept: application/sdp, application/sdp Accept-Language: en Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri User-Agent: Z 3.3.25608 r25552 Allow-Events: presence, kpml Content-Length: 0 <-------------> [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK7230e8b8 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 2 [ 34]: Contact: [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 3 [ 88]: To: ;tag=cc930138 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 4 [ 59]: From: "asterisk";tag=as5c124d20 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 5 [ 60]: Call-ID: 3e537f011fbac93f361badc26f148c95@172.28.128.20:5060 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 6 [ 17]: CSeq: 102 OPTIONS [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 7 [ 40]: Accept: application/sdp, application/sdp [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 10 [ 74]: Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 11 [ 30]: User-Agent: Z 3.3.25608 r25552 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 12 [ 28]: Allow-Events: presence, kpml [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Sep 1 20:50:23] VERBOSE[1321] chan_sip.c: --- (14 headers 0 lines) --- [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: = Looking for Call ID: 3e537f011fbac93f361badc26f148c95@172.28.128.20:5060 (Checking To) --From tag as5c124d20 --To-tag cc930138 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #5 [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Stopping retransmission on '3e537f011fbac93f361badc26f148c95@172.28.128.20:5060' of Request 102: Match Found [Sep 1 20:50:23] DEBUG[1321] chan_sip.c: Destroying SIP dialog 3e537f011fbac93f361badc26f148c95@172.28.128.20:5060 [Sep 1 20:50:23] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '3e537f011fbac93f361badc26f148c95@172.28.128.20:5060' Method: OPTIONS [Sep 1 20:50:25] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:50:30] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:50:34] DEBUG[1298] res_pjsip_registrar.c: Woke up at 1599007834 Interval: 30 [Sep 1 20:50:34] DEBUG[1298] res_pjsip_registrar.c: Expiring 0 contacts [Sep 1 20:50:35] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:50:39] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:50:45] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:50:48] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:50:49] VERBOSE[1459] asterisk.c: Remote UNIX connection disconnected [Sep 1 20:50:52] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:50:58] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:03] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:04] DEBUG[1298] res_pjsip_registrar.c: Woke up at 1599007864 Interval: 30 [Sep 1 20:51:04] DEBUG[1298] res_pjsip_registrar.c: Expiring 0 contacts [Sep 1 20:51:08] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:13] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:17] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 3f1bdf027acc79fe08a1acd83661b6d7@[fe80::630d:d8c5:2cd9:85b8]:5060 - OPTIONS (No RTP) [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Sep 1 20:51:23] DEBUG[1321] acl.c: For destination '172.28.128.200', our source address is '172.28.128.20'. [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: SIP call-id changed from '3f1bdf027acc79fe08a1acd83661b6d7@[fe80::630d:d8c5:2cd9:85b8]:5060' to '55f2c6827367b2337892d7684444acd6@172.28.128.20:5060' [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Initializing initreq for method OPTIONS - callid 55f2c6827367b2337892d7684444acd6@172.28.128.20:5060 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 0 [ 85]: OPTIONS sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK7e6e6818 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as4f5c5536 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 4 [ 75]: To: [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 5 [ 42]: Contact: [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 6 [ 60]: Call-ID: 55f2c6827367b2337892d7684444acd6@172.28.128.20:5060 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 8 [ 35]: User-Agent: Asterisk PBX 16.8.0.ips [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 9 [ 35]: Date: Wed, 02 Sep 2020 00:51:23 GMT [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Sep 1 20:51:23] VERBOSE[1321] chan_sip.c: Reliably Transmitting (no NAT) to 172.28.128.200:5060: OPTIONS sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK7e6e6818 Max-Forwards: 70 From: "asterisk" ;tag=as4f5c5536 To: Contact: Call-ID: 55f2c6827367b2337892d7684444acd6@172.28.128.20:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 16.8.0.ips Date: Wed, 02 Sep 2020 00:51:23 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #12 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.28.128.200:5060 [Sep 1 20:51:23] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK7e6e6818 Contact: To: ;tag=1cf98e65 From: "asterisk";tag=as4f5c5536 Call-ID: 55f2c6827367b2337892d7684444acd6@172.28.128.20:5060 CSeq: 102 OPTIONS Accept: application/sdp, application/sdp Accept-Language: en Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri User-Agent: Z 3.3.25608 r25552 Allow-Events: presence, kpml Content-Length: 0 <-------------> [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK7e6e6818 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 2 [ 34]: Contact: [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 3 [ 88]: To: ;tag=1cf98e65 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 4 [ 59]: From: "asterisk";tag=as4f5c5536 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 5 [ 60]: Call-ID: 55f2c6827367b2337892d7684444acd6@172.28.128.20:5060 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 6 [ 17]: CSeq: 102 OPTIONS [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 7 [ 40]: Accept: application/sdp, application/sdp [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 10 [ 74]: Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 11 [ 30]: User-Agent: Z 3.3.25608 r25552 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 12 [ 28]: Allow-Events: presence, kpml [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Sep 1 20:51:23] VERBOSE[1321] chan_sip.c: --- (14 headers 0 lines) --- [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: = Looking for Call ID: 55f2c6827367b2337892d7684444acd6@172.28.128.20:5060 (Checking To) --From tag as4f5c5536 --To-tag 1cf98e65 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #12 [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Stopping retransmission on '55f2c6827367b2337892d7684444acd6@172.28.128.20:5060' of Request 102: Match Found [Sep 1 20:51:23] DEBUG[1321] chan_sip.c: Destroying SIP dialog 55f2c6827367b2337892d7684444acd6@172.28.128.20:5060 [Sep 1 20:51:23] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '55f2c6827367b2337892d7684444acd6@172.28.128.20:5060' Method: OPTIONS [Sep 1 20:51:23] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:28] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:33] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:34] DEBUG[1298] res_pjsip_registrar.c: Woke up at 1599007894 Interval: 30 [Sep 1 20:51:34] DEBUG[1298] res_pjsip_registrar.c: Expiring 0 contacts [Sep 1 20:51:38] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:42] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:47] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:52] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:51:57] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:52:03] DEBUG[1477][C-00000005] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.28.128.200:8001 [Sep 1 20:52:04] DEBUG[1298] res_pjsip_registrar.c: Woke up at 1599007924 Interval: 30 [Sep 1 20:52:04] DEBUG[1298] res_pjsip_registrar.c: Expiring 0 contacts [Sep 1 20:52:06] DEBUG[1477][C-00000005] pbx.c: Launching 'Hangup' [Sep 1 20:52:06] VERBOSE[1477][C-00000005] pbx.c: Executing [s@bridgewait-forever:4] Hangup("SIP/9000-00000001", "") in new stack [Sep 1 20:52:06] DEBUG[1477][C-00000005] channel.c: Soft-Hanging (0x20) up channel 'SIP/9000-00000001' [Sep 1 20:52:06] DEBUG[1477][C-00000005] pbx.c: Spawn extension (bridgewait-forever,s,4) exited non-zero on 'SIP/9000-00000001' [Sep 1 20:52:06] VERBOSE[1477][C-00000005] pbx.c: Spawn extension (bridgewait-forever, s, 4) exited non-zero on 'SIP/9000-00000001' [Sep 1 20:52:06] DEBUG[1477][C-00000005] channel.c: Soft-Hanging (0x10) up channel 'SIP/9000-00000001' [Sep 1 20:52:06] DEBUG[1477][C-00000005] channel.c: Channel 0x147de804f670 'SIP/9000-00000001' hanging up. Refs: 2 [Sep 1 20:52:06] DEBUG[1477][C-00000005] chan_sip.c: Hangup call SIP/9000-00000001, SIP callid 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 [Sep 1 20:52:06] VERBOSE[1477][C-00000005] chan_sip.c: Scheduling destruction of SIP dialog '226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060' in 6400 ms (Method: INVITE) [Sep 1 20:52:06] DEBUG[1477][C-00000005] chan_sip.c: Strict routing enforced for session 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 [Sep 1 20:52:06] VERBOSE[1477][C-00000005] chan_sip.c: set_destination: Parsing for address/port to send to [Sep 1 20:52:06] DEBUG[1477][C-00000005] netsock2.c: Splitting '172.28.128.200:5060' into... [Sep 1 20:52:06] DEBUG[1477][C-00000005] netsock2.c: ...host '172.28.128.200' and port '5060'. [Sep 1 20:52:06] VERBOSE[1477][C-00000005] chan_sip.c: set_destination: set destination to 172.28.128.200:5060 [Sep 1 20:52:06] VERBOSE[1477][C-00000005] chan_sip.c: Reliably Transmitting (no NAT) to 172.28.128.200:5060: BYE sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK1b02ed2a Max-Forwards: 70 From: "Anonymous" ;tag=as165dcdc6 To: ;tag=92cf4279 Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 CSeq: 103 BYE User-Agent: Asterisk PBX 16.8.0.ips X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- [Sep 1 20:52:06] DEBUG[1477][C-00000005] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #4 [Sep 1 20:52:06] DEBUG[1477][C-00000005] chan_sip.c: Trying to put 'BYE sip:900' onto UDP socket destined for 172.28.128.200:5060 [Sep 1 20:52:06] DEBUG[1477][C-00000005] channel.c: Channel 0x147de804f670 'SIP/9000-00000001' destroying [Sep 1 20:52:06] DEBUG[1477][C-00000005] stasis.c: Destroying topic. name: cache:32/channel:1599007747.13, detail: [Sep 1 20:52:06] DEBUG[1477][C-00000005] stasis.c: Topic 'cache:32/channel:1599007747.13': 0x555896e09790 destroyed [Sep 1 20:52:06] DEBUG[1477][C-00000005] stasis.c: Destroying topic. name: channel:1599007747.13, detail: [Sep 1 20:52:06] DEBUG[1477][C-00000005] stasis.c: Topic 'channel:1599007747.13': 0x555896cf39d0 destroyed [Sep 1 20:52:06] DEBUG[1278] cdr.c: Finalized CDR for SIP/9000-00000001 - start 1599007796.446550 answer 1599007796.446550 end 1599007926.449888 dur 130.003 bill 130.003 dispo ANSWERED [Sep 1 20:52:06] DEBUG[1278] cdr.c: CDR for SIP/9000-00000001 is dialed and has no Party B; discarding [Sep 1 20:52:06] DEBUG[1278] stasis.c: Creating topic. name: channel:1599007926.20, detail: [Sep 1 20:52:06] DEBUG[1278] stasis.c: Topic 'channel:1599007926.20': 0x147de4007590 created [Sep 1 20:52:06] DEBUG[1278] stasis.c: Creating topic. name: cache:43/channel:1599007926.20, detail: [Sep 1 20:52:06] DEBUG[1278] stasis.c: Topic 'cache:43/channel:1599007926.20': 0x147de8098cd0 created [Sep 1 20:52:06] DEBUG[1278] stasis.c: Destroying topic. name: cache:43/channel:1599007926.20, detail: [Sep 1 20:52:06] DEBUG[1278] stasis.c: Topic 'cache:43/channel:1599007926.20': 0x147de8098cd0 destroyed [Sep 1 20:52:06] DEBUG[1278] stasis.c: Destroying topic. name: channel:1599007926.20, detail: [Sep 1 20:52:06] DEBUG[1278] stasis.c: Topic 'channel:1599007926.20': 0x147de4007590 destroyed [Sep 1 20:52:06] DEBUG[1278] stasis.c: Creating topic. name: channel:1599007926.21, detail: [Sep 1 20:52:06] DEBUG[1278] stasis.c: Topic 'channel:1599007926.21': 0x147de80bb260 created [Sep 1 20:52:06] DEBUG[1278] stasis.c: Creating topic. name: cache:44/channel:1599007926.21, detail: [Sep 1 20:52:06] DEBUG[1278] stasis.c: Topic 'cache:44/channel:1599007926.21': 0x147de804b860 created [Sep 1 20:52:06] DEBUG[1278] stasis.c: Destroying topic. name: cache:44/channel:1599007926.21, detail: [Sep 1 20:52:06] DEBUG[1278] stasis.c: Topic 'cache:44/channel:1599007926.21': 0x147de804b860 destroyed [Sep 1 20:52:06] DEBUG[1278] stasis.c: Destroying topic. name: channel:1599007926.21, detail: [Sep 1 20:52:06] DEBUG[1278] stasis.c: Topic 'channel:1599007926.21': 0x147de80bb260 destroyed [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: Session timer stopped: 10 - 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 [Sep 1 20:52:06] DEBUG[1258] threadpool.c: Increasing threadpool stasis/pool's size by 1 [Sep 1 20:52:06] DEBUG[1270] devicestate.c: No provider found, checking channel drivers for SIP - 9000 [Sep 1 20:52:06] DEBUG[1270] chan_sip.c: Checking device state for peer 9000 [Sep 1 20:52:06] DEBUG[1270] devicestate.c: Changing state for SIP/9000 - state 1 (Not in use) [Sep 1 20:52:06] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK1b02ed2a Contact: To: ;tag=92cf4279 From: "Anonymous";tag=as165dcdc6 Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 CSeq: 103 BYE User-Agent: Z 3.3.25608 r25552 Content-Length: 0 <-------------> [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK1b02ed2a [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: Header 2 [ 80]: Contact: [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: Header 3 [ 88]: To: ;tag=92cf4279 [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: Header 4 [ 65]: From: "Anonymous";tag=as165dcdc6 [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: Header 5 [ 60]: Call-ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: Header 6 [ 13]: CSeq: 103 BYE [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: Header 7 [ 30]: User-Agent: Z 3.3.25608 r25552 [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Sep 1 20:52:06] VERBOSE[1321] chan_sip.c: --- (9 headers 0 lines) --- [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: = Looking for Call ID: 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 (Checking To) --From tag as165dcdc6 --To-tag 92cf4279 [Sep 1 20:52:06] DEBUG[1321][C-00000005] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #4 [Sep 1 20:52:06] DEBUG[1321][C-00000005] chan_sip.c: Stopping retransmission on '226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060' of Request 103: Match Found [Sep 1 20:52:06] DEBUG[1321] chan_sip.c: Destroying SIP dialog 226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060 [Sep 1 20:52:06] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '226f0ddd3395b8ee3484a64436082777@172.28.128.20:5060' Method: INVITE [Sep 1 20:52:06] DEBUG[1321] rtp_engine.c: Destroyed RTP instance '0x147de80193b0' [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 7a5a665f38c8b11a45c5103e0a7f910c@[fe80::630d:d8c5:2cd9:85b8]:5060 - OPTIONS (No RTP) [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Sep 1 20:52:23] DEBUG[1321] acl.c: For destination '172.28.128.200', our source address is '172.28.128.20'. [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: SIP call-id changed from '7a5a665f38c8b11a45c5103e0a7f910c@[fe80::630d:d8c5:2cd9:85b8]:5060' to '489086f6652d2d367c06e62a16c0788d@172.28.128.20:5060' [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Initializing initreq for method OPTIONS - callid 489086f6652d2d367c06e62a16c0788d@172.28.128.20:5060 [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 0 [ 85]: OPTIONS sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK2cf2131e [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as5675cafd [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 4 [ 75]: To: [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 5 [ 42]: Contact: [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 6 [ 60]: Call-ID: 489086f6652d2d367c06e62a16c0788d@172.28.128.20:5060 [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 8 [ 35]: User-Agent: Asterisk PBX 16.8.0.ips [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 9 [ 35]: Date: Wed, 02 Sep 2020 00:52:23 GMT [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Sep 1 20:52:23] VERBOSE[1321] chan_sip.c: Reliably Transmitting (no NAT) to 172.28.128.200:5060: OPTIONS sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK2cf2131e Max-Forwards: 70 From: "asterisk" ;tag=as5675cafd To: Contact: Call-ID: 489086f6652d2d367c06e62a16c0788d@172.28.128.20:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 16.8.0.ips Date: Wed, 02 Sep 2020 00:52:23 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #6 [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.28.128.200:5060 [Sep 1 20:52:23] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK2cf2131e Contact: To: ;tag=2a3fab26 From: "asterisk";tag=as5675cafd Call-ID: 489086f6652d2d367c06e62a16c0788d@172.28.128.20:5060 CSeq: 102 OPTIONS Accept: application/sdp, application/sdp Accept-Language: en Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri User-Agent: Z 3.3.25608 r25552 Allow-Events: presence, kpml Content-Length: 0 <-------------> [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK2cf2131e [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 2 [ 34]: Contact: [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 3 [ 88]: To: ;tag=2a3fab26 [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 4 [ 59]: From: "asterisk";tag=as5675cafd [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 5 [ 60]: Call-ID: 489086f6652d2d367c06e62a16c0788d@172.28.128.20:5060 [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 6 [ 17]: CSeq: 102 OPTIONS [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 7 [ 40]: Accept: application/sdp, application/sdp [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 10 [ 74]: Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 11 [ 30]: User-Agent: Z 3.3.25608 r25552 [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 12 [ 28]: Allow-Events: presence, kpml [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Sep 1 20:52:23] VERBOSE[1321] chan_sip.c: --- (14 headers 0 lines) --- [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: = Looking for Call ID: 489086f6652d2d367c06e62a16c0788d@172.28.128.20:5060 (Checking To) --From tag as5675cafd --To-tag 2a3fab26 [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #6 [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Stopping retransmission on '489086f6652d2d367c06e62a16c0788d@172.28.128.20:5060' of Request 102: Match Found [Sep 1 20:52:23] DEBUG[1321] chan_sip.c: Destroying SIP dialog 489086f6652d2d367c06e62a16c0788d@172.28.128.20:5060 [Sep 1 20:52:23] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '489086f6652d2d367c06e62a16c0788d@172.28.128.20:5060' Method: OPTIONS [Sep 1 20:52:26] DEBUG[1488] threadpool.c: Worker thread idle timeout reached. Dying. [Sep 1 20:52:26] DEBUG[1258] threadpool.c: Destroying worker thread 30 [Sep 1 20:52:27] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKca23.b3b95261000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-42fb CSeq: 10 REGISTER Call-ID: 501f11182f3fb39d-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 <-------------> [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKca23.b3b95261000000000000000000000000.0 [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-42fb [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 10 REGISTER [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb39d-20956@172.28.128.100 [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:52:27] VERBOSE[1321] chan_sip.c: --- (11 headers 0 lines) --- [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb39d-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-42fb --To-tag [Sep 1 20:52:27] DEBUG[1321] acl.c: For destination '172.28.128.100', our source address is '172.28.128.20'. [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:52:27] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:27] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:27] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 501f11182f3fb39d-20956@172.28.128.100 - REGISTER (No RTP) [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb39d-20956@172.28.128.100 [Sep 1 20:52:27] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:27] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:27] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:27] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:52:27] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:52:27] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKca23.b3b95261000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-42fb To: ;tag=as69592143 Call-ID: 501f11182f3fb39d-20956@172.28.128.100 CSeq: 10 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="7fa2d579" Content-Length: 0 <------------> [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:52:27] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb39d-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:52:27] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKda23.4069df67000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-42fb CSeq: 11 REGISTER Call-ID: 501f11182f3fb39d-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 Authorization: Digest username="sbc", realm="asterisk", nonce="7fa2d579", uri="sip:172.28.128.20", response="f0638d1d2e6c3a1ebcd2633da36b0521", algorithm=MD5 <-------------> [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKda23.4069df67000000000000000000000000.0 [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-42fb [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 11 REGISTER [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb39d-20956@172.28.128.100 [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Header 11 [157]: Authorization: Digest username="sbc", realm="asterisk", nonce="7fa2d579", uri="sip:172.28.128.20", response="f0638d1d2e6c3a1ebcd2633da36b0521", algorithm=MD5 [Sep 1 20:52:27] VERBOSE[1321] chan_sip.c: --- (12 headers 0 lines) --- [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb39d-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-42fb --To-tag [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb39d-20956@172.28.128.100 [Sep 1 20:52:27] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:27] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:27] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:27] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:52:27] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:52:27] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKda23.4069df67000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-42fb To: ;tag=as69592143 Call-ID: 501f11182f3fb39d-20956@172.28.128.100 CSeq: 11 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:52:27] NOTICE[1321] chan_sip.c: Registration from '' failed for '172.28.128.100:5060' - Wrong password [Sep 1 20:52:27] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb39d-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:52:27] DEBUG[1321] chan_sip.c: SIP message could not be handled, bad request: 501f11182f3fb39d-20956@172.28.128.100 [Sep 1 20:52:34] DEBUG[1298] res_pjsip_registrar.c: Woke up at 1599007954 Interval: 30 [Sep 1 20:52:34] DEBUG[1298] res_pjsip_registrar.c: Expiring 0 contacts [Sep 1 20:52:37] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKda23.69da9dd5000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9761 CSeq: 10 REGISTER Call-ID: 501f11182f3fb39e-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 <-------------> [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKda23.69da9dd5000000000000000000000000.0 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9761 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 10 REGISTER [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb39e-20956@172.28.128.100 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:52:37] VERBOSE[1321] chan_sip.c: --- (11 headers 0 lines) --- [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb39e-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-9761 --To-tag [Sep 1 20:52:37] DEBUG[1321] acl.c: For destination '172.28.128.100', our source address is '172.28.128.20'. [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:52:37] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:37] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:37] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 501f11182f3fb39e-20956@172.28.128.100 - REGISTER (No RTP) [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb39e-20956@172.28.128.100 [Sep 1 20:52:37] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:37] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:37] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:37] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:52:37] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:52:37] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKda23.69da9dd5000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9761 To: ;tag=as58ca1065 Call-ID: 501f11182f3fb39e-20956@172.28.128.100 CSeq: 10 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="6e0c1747" Content-Length: 0 <------------> [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:52:37] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb39e-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:52:37] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKea23.f2728921000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9761 CSeq: 11 REGISTER Call-ID: 501f11182f3fb39e-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 Authorization: Digest username="sbc", realm="asterisk", nonce="6e0c1747", uri="sip:172.28.128.20", response="d33407e72e171f1d20eb950d17af1dfe", algorithm=MD5 <-------------> [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKea23.f2728921000000000000000000000000.0 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9761 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 11 REGISTER [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb39e-20956@172.28.128.100 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Header 11 [157]: Authorization: Digest username="sbc", realm="asterisk", nonce="6e0c1747", uri="sip:172.28.128.20", response="d33407e72e171f1d20eb950d17af1dfe", algorithm=MD5 [Sep 1 20:52:37] VERBOSE[1321] chan_sip.c: --- (12 headers 0 lines) --- [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb39e-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-9761 --To-tag [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb39e-20956@172.28.128.100 [Sep 1 20:52:37] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:37] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:37] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:37] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:52:37] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:52:37] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKea23.f2728921000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9761 To: ;tag=as58ca1065 Call-ID: 501f11182f3fb39e-20956@172.28.128.100 CSeq: 11 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:52:37] NOTICE[1321] chan_sip.c: Registration from '' failed for '172.28.128.100:5060' - Wrong password [Sep 1 20:52:37] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb39e-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:52:37] DEBUG[1321] chan_sip.c: SIP message could not be handled, bad request: 501f11182f3fb39e-20956@172.28.128.100 [Sep 1 20:52:47] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKea23.e36b6205000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f85e CSeq: 10 REGISTER Call-ID: 501f11182f3fb39f-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 <-------------> [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKea23.e36b6205000000000000000000000000.0 [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f85e [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 10 REGISTER [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb39f-20956@172.28.128.100 [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:52:47] VERBOSE[1321] chan_sip.c: --- (11 headers 0 lines) --- [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb39f-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-f85e --To-tag [Sep 1 20:52:47] DEBUG[1321] acl.c: For destination '172.28.128.100', our source address is '172.28.128.20'. [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:52:47] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:47] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:47] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 501f11182f3fb39f-20956@172.28.128.100 - REGISTER (No RTP) [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb39f-20956@172.28.128.100 [Sep 1 20:52:47] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:47] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:47] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:47] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:52:47] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:52:47] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKea23.e36b6205000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f85e To: ;tag=as0e5f0dcf Call-ID: 501f11182f3fb39f-20956@172.28.128.100 CSeq: 10 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="096c18e7" Content-Length: 0 <------------> [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:52:47] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb39f-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:52:47] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKfa23.1d050037000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f85e CSeq: 11 REGISTER Call-ID: 501f11182f3fb39f-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 Authorization: Digest username="sbc", realm="asterisk", nonce="096c18e7", uri="sip:172.28.128.20", response="946028c3a78ad0769b10767d57767f41", algorithm=MD5 <-------------> [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKfa23.1d050037000000000000000000000000.0 [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f85e [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 11 REGISTER [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb39f-20956@172.28.128.100 [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Header 11 [157]: Authorization: Digest username="sbc", realm="asterisk", nonce="096c18e7", uri="sip:172.28.128.20", response="946028c3a78ad0769b10767d57767f41", algorithm=MD5 [Sep 1 20:52:47] VERBOSE[1321] chan_sip.c: --- (12 headers 0 lines) --- [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb39f-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-f85e --To-tag [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb39f-20956@172.28.128.100 [Sep 1 20:52:47] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:47] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:47] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:47] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:52:47] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:52:47] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKfa23.1d050037000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f85e To: ;tag=as0e5f0dcf Call-ID: 501f11182f3fb39f-20956@172.28.128.100 CSeq: 11 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:52:47] NOTICE[1321] chan_sip.c: Registration from '' failed for '172.28.128.100:5060' - Wrong password [Sep 1 20:52:47] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb39f-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:52:47] DEBUG[1321] chan_sip.c: SIP message could not be handled, bad request: 501f11182f3fb39f-20956@172.28.128.100 [Sep 1 20:52:57] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKe61e.17b657f1000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-4981 CSeq: 10 REGISTER Call-ID: 501f11182f3fb3a0-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 <-------------> [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKe61e.17b657f1000000000000000000000000.0 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-4981 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 10 REGISTER [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a0-20956@172.28.128.100 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:52:57] VERBOSE[1321] chan_sip.c: --- (11 headers 0 lines) --- [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a0-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-4981 --To-tag [Sep 1 20:52:57] DEBUG[1321] acl.c: For destination '172.28.128.100', our source address is '172.28.128.20'. [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:52:57] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:57] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:57] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 501f11182f3fb3a0-20956@172.28.128.100 - REGISTER (No RTP) [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a0-20956@172.28.128.100 [Sep 1 20:52:57] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:57] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:57] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:57] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:52:57] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:52:57] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKe61e.17b657f1000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-4981 To: ;tag=as2e6cd149 Call-ID: 501f11182f3fb3a0-20956@172.28.128.100 CSeq: 10 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="66f2e195" Content-Length: 0 <------------> [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:52:57] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a0-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:52:57] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKf61e.60d18651000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-4981 CSeq: 11 REGISTER Call-ID: 501f11182f3fb3a0-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 Authorization: Digest username="sbc", realm="asterisk", nonce="66f2e195", uri="sip:172.28.128.20", response="d5e20e3b28bb60e2232106ae94df9471", algorithm=MD5 <-------------> [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKf61e.60d18651000000000000000000000000.0 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-4981 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 11 REGISTER [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a0-20956@172.28.128.100 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Header 11 [157]: Authorization: Digest username="sbc", realm="asterisk", nonce="66f2e195", uri="sip:172.28.128.20", response="d5e20e3b28bb60e2232106ae94df9471", algorithm=MD5 [Sep 1 20:52:57] VERBOSE[1321] chan_sip.c: --- (12 headers 0 lines) --- [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a0-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-4981 --To-tag [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a0-20956@172.28.128.100 [Sep 1 20:52:57] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:52:57] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:52:57] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:52:57] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:52:57] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:52:57] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKf61e.60d18651000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-4981 To: ;tag=as2e6cd149 Call-ID: 501f11182f3fb3a0-20956@172.28.128.100 CSeq: 11 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:52:57] NOTICE[1321] chan_sip.c: Registration from '' failed for '172.28.128.100:5060' - Wrong password [Sep 1 20:52:57] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a0-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:52:57] DEBUG[1321] chan_sip.c: SIP message could not be handled, bad request: 501f11182f3fb3a0-20956@172.28.128.100 [Sep 1 20:52:59] DEBUG[1321] chan_sip.c: Auto destroying SIP dialog '501f11182f3fb39d-20956@172.28.128.100' [Sep 1 20:52:59] DEBUG[1321] chan_sip.c: Destroying SIP dialog 501f11182f3fb39d-20956@172.28.128.100 [Sep 1 20:52:59] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '501f11182f3fb39d-20956@172.28.128.100' Method: REGISTER [Sep 1 20:53:04] DEBUG[1298] res_pjsip_registrar.c: Woke up at 1599007984 Interval: 30 [Sep 1 20:53:04] DEBUG[1298] res_pjsip_registrar.c: Expiring 0 contacts [Sep 1 20:53:07] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKf61e.52720646000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9c1b CSeq: 10 REGISTER Call-ID: 501f11182f3fb3a1-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 <-------------> [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKf61e.52720646000000000000000000000000.0 [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9c1b [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 10 REGISTER [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a1-20956@172.28.128.100 [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:07] VERBOSE[1321] chan_sip.c: --- (11 headers 0 lines) --- [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a1-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-9c1b --To-tag [Sep 1 20:53:07] DEBUG[1321] acl.c: For destination '172.28.128.100', our source address is '172.28.128.20'. [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:53:07] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:07] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:07] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 501f11182f3fb3a1-20956@172.28.128.100 - REGISTER (No RTP) [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a1-20956@172.28.128.100 [Sep 1 20:53:07] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:07] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:07] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:07] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:07] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:07] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKf61e.52720646000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9c1b To: ;tag=as3f029c57 Call-ID: 501f11182f3fb3a1-20956@172.28.128.100 CSeq: 10 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="06cb583a" Content-Length: 0 <------------> [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:07] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a1-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:07] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bK071e.86030752000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9c1b CSeq: 11 REGISTER Call-ID: 501f11182f3fb3a1-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 Authorization: Digest username="sbc", realm="asterisk", nonce="06cb583a", uri="sip:172.28.128.20", response="5e956269dc994a83695d9027197a1862", algorithm=MD5 <-------------> [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bK071e.86030752000000000000000000000000.0 [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9c1b [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 11 REGISTER [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a1-20956@172.28.128.100 [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Header 11 [157]: Authorization: Digest username="sbc", realm="asterisk", nonce="06cb583a", uri="sip:172.28.128.20", response="5e956269dc994a83695d9027197a1862", algorithm=MD5 [Sep 1 20:53:07] VERBOSE[1321] chan_sip.c: --- (12 headers 0 lines) --- [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a1-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-9c1b --To-tag [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a1-20956@172.28.128.100 [Sep 1 20:53:07] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:07] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:07] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:07] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:07] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:07] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bK071e.86030752000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-9c1b To: ;tag=as3f029c57 Call-ID: 501f11182f3fb3a1-20956@172.28.128.100 CSeq: 11 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:07] NOTICE[1321] chan_sip.c: Registration from '' failed for '172.28.128.100:5060' - Wrong password [Sep 1 20:53:07] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a1-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:07] DEBUG[1321] chan_sip.c: SIP message could not be handled, bad request: 501f11182f3fb3a1-20956@172.28.128.100 [Sep 1 20:53:09] DEBUG[1321] chan_sip.c: Auto destroying SIP dialog '501f11182f3fb39e-20956@172.28.128.100' [Sep 1 20:53:09] DEBUG[1321] chan_sip.c: Destroying SIP dialog 501f11182f3fb39e-20956@172.28.128.100 [Sep 1 20:53:09] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '501f11182f3fb39e-20956@172.28.128.100' Method: REGISTER [Sep 1 20:53:17] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKc61e.845c2da7000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f324 CSeq: 10 REGISTER Call-ID: 501f11182f3fb3a2-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 <-------------> [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKc61e.845c2da7000000000000000000000000.0 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f324 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 10 REGISTER [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a2-20956@172.28.128.100 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:17] VERBOSE[1321] chan_sip.c: --- (11 headers 0 lines) --- [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a2-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-f324 --To-tag [Sep 1 20:53:17] DEBUG[1321] acl.c: For destination '172.28.128.100', our source address is '172.28.128.20'. [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:53:17] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:17] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:17] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 501f11182f3fb3a2-20956@172.28.128.100 - REGISTER (No RTP) [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a2-20956@172.28.128.100 [Sep 1 20:53:17] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:17] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:17] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:17] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:17] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:17] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKc61e.845c2da7000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f324 To: ;tag=as72e1d35e Call-ID: 501f11182f3fb3a2-20956@172.28.128.100 CSeq: 10 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="2484ad4a" Content-Length: 0 <------------> [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:17] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a2-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:17] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKd61e.d29b6b40000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f324 CSeq: 11 REGISTER Call-ID: 501f11182f3fb3a2-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 Authorization: Digest username="sbc", realm="asterisk", nonce="2484ad4a", uri="sip:172.28.128.20", response="4d5834912a80a1d89879b40853b0ef3a", algorithm=MD5 <-------------> [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKd61e.d29b6b40000000000000000000000000.0 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f324 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 11 REGISTER [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a2-20956@172.28.128.100 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Header 11 [157]: Authorization: Digest username="sbc", realm="asterisk", nonce="2484ad4a", uri="sip:172.28.128.20", response="4d5834912a80a1d89879b40853b0ef3a", algorithm=MD5 [Sep 1 20:53:17] VERBOSE[1321] chan_sip.c: --- (12 headers 0 lines) --- [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a2-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-f324 --To-tag [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a2-20956@172.28.128.100 [Sep 1 20:53:17] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:17] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:17] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:17] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:17] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:17] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKd61e.d29b6b40000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f324 To: ;tag=as72e1d35e Call-ID: 501f11182f3fb3a2-20956@172.28.128.100 CSeq: 11 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:17] NOTICE[1321] chan_sip.c: Registration from '' failed for '172.28.128.100:5060' - Wrong password [Sep 1 20:53:17] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a2-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:17] DEBUG[1321] chan_sip.c: SIP message could not be handled, bad request: 501f11182f3fb3a2-20956@172.28.128.100 [Sep 1 20:53:19] DEBUG[1321] chan_sip.c: Auto destroying SIP dialog '501f11182f3fb39f-20956@172.28.128.100' [Sep 1 20:53:19] DEBUG[1321] chan_sip.c: Destroying SIP dialog 501f11182f3fb39f-20956@172.28.128.100 [Sep 1 20:53:19] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '501f11182f3fb39f-20956@172.28.128.100' Method: REGISTER [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 0494f5f80f1087223549bd5b02fef5c6@[fe80::630d:d8c5:2cd9:85b8]:5060 - OPTIONS (No RTP) [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Sep 1 20:53:23] DEBUG[1321] acl.c: For destination '172.28.128.200', our source address is '172.28.128.20'. [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: SIP call-id changed from '0494f5f80f1087223549bd5b02fef5c6@[fe80::630d:d8c5:2cd9:85b8]:5060' to '1be84ff522c82a821df3d2cf1ae7f867@172.28.128.20:5060' [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Initializing initreq for method OPTIONS - callid 1be84ff522c82a821df3d2cf1ae7f867@172.28.128.20:5060 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 0 [ 85]: OPTIONS sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK154bb128 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 3 [ 60]: From: "asterisk" ;tag=as05f82b71 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 4 [ 75]: To: [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 5 [ 42]: Contact: [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 6 [ 60]: Call-ID: 1be84ff522c82a821df3d2cf1ae7f867@172.28.128.20:5060 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 8 [ 35]: User-Agent: Asterisk PBX 16.8.0.ips [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 9 [ 35]: Date: Wed, 02 Sep 2020 00:53:23 GMT [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 10 [ 90]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Sep 1 20:53:23] VERBOSE[1321] chan_sip.c: Reliably Transmitting (no NAT) to 172.28.128.200:5060: OPTIONS sip:9000@172.28.128.200:5060;rinstance=5f386d651cac737f;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK154bb128 Max-Forwards: 70 From: "asterisk" ;tag=as05f82b71 To: Contact: Call-ID: 1be84ff522c82a821df3d2cf1ae7f867@172.28.128.20:5060 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 16.8.0.ips Date: Wed, 02 Sep 2020 00:53:23 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 --- [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #2 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.28.128.200:5060 [Sep 1 20:53:23] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.200:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK154bb128 Contact: To: ;tag=b68b9b57 From: "asterisk";tag=as05f82b71 Call-ID: 1be84ff522c82a821df3d2cf1ae7f867@172.28.128.20:5060 CSeq: 102 OPTIONS Accept: application/sdp, application/sdp Accept-Language: en Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri User-Agent: Z 3.3.25608 r25552 Allow-Events: presence, kpml Content-Length: 0 <-------------> [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 172.28.128.20:5060;branch=z9hG4bK154bb128 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 2 [ 34]: Contact: [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 3 [ 88]: To: ;tag=b68b9b57 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 4 [ 59]: From: "asterisk";tag=as05f82b71 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 5 [ 60]: Call-ID: 1be84ff522c82a821df3d2cf1ae7f867@172.28.128.20:5060 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 6 [ 17]: CSeq: 102 OPTIONS [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 7 [ 40]: Accept: application/sdp, application/sdp [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 10 [ 74]: Supported: replaces, norefersub, extended-refer, timer, X-cisco-serviceuri [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 11 [ 30]: User-Agent: Z 3.3.25608 r25552 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 12 [ 28]: Allow-Events: presence, kpml [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Sep 1 20:53:23] VERBOSE[1321] chan_sip.c: --- (14 headers 0 lines) --- [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: = Looking for Call ID: 1be84ff522c82a821df3d2cf1ae7f867@172.28.128.20:5060 (Checking To) --From tag as05f82b71 --To-tag b68b9b57 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #2 [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Stopping retransmission on '1be84ff522c82a821df3d2cf1ae7f867@172.28.128.20:5060' of Request 102: Match Found [Sep 1 20:53:23] DEBUG[1321] chan_sip.c: Destroying SIP dialog 1be84ff522c82a821df3d2cf1ae7f867@172.28.128.20:5060 [Sep 1 20:53:23] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '1be84ff522c82a821df3d2cf1ae7f867@172.28.128.20:5060' Method: OPTIONS [Sep 1 20:53:27] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKd61e.13e962c5000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-26be CSeq: 10 REGISTER Call-ID: 501f11182f3fb3a3-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 <-------------> [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKd61e.13e962c5000000000000000000000000.0 [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-26be [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 10 REGISTER [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a3-20956@172.28.128.100 [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:27] VERBOSE[1321] chan_sip.c: --- (11 headers 0 lines) --- [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a3-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-26be --To-tag [Sep 1 20:53:27] DEBUG[1321] acl.c: For destination '172.28.128.100', our source address is '172.28.128.20'. [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:53:27] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:27] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:27] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 501f11182f3fb3a3-20956@172.28.128.100 - REGISTER (No RTP) [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a3-20956@172.28.128.100 [Sep 1 20:53:27] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:27] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:27] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:27] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:27] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:27] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKd61e.13e962c5000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-26be To: ;tag=as1e1aa776 Call-ID: 501f11182f3fb3a3-20956@172.28.128.100 CSeq: 10 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="34234b3c" Content-Length: 0 <------------> [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:27] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a3-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:27] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKe61e.d97ac351000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-26be CSeq: 11 REGISTER Call-ID: 501f11182f3fb3a3-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 Authorization: Digest username="sbc", realm="asterisk", nonce="34234b3c", uri="sip:172.28.128.20", response="9a57265ac485319f42caafae215c3e3f", algorithm=MD5 <-------------> [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKe61e.d97ac351000000000000000000000000.0 [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-26be [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 11 REGISTER [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a3-20956@172.28.128.100 [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Header 11 [157]: Authorization: Digest username="sbc", realm="asterisk", nonce="34234b3c", uri="sip:172.28.128.20", response="9a57265ac485319f42caafae215c3e3f", algorithm=MD5 [Sep 1 20:53:27] VERBOSE[1321] chan_sip.c: --- (12 headers 0 lines) --- [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a3-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-26be --To-tag [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a3-20956@172.28.128.100 [Sep 1 20:53:27] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:27] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:27] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:27] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:27] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:27] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKe61e.d97ac351000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-26be To: ;tag=as1e1aa776 Call-ID: 501f11182f3fb3a3-20956@172.28.128.100 CSeq: 11 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:27] NOTICE[1321] chan_sip.c: Registration from '' failed for '172.28.128.100:5060' - Wrong password [Sep 1 20:53:27] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a3-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:27] DEBUG[1321] chan_sip.c: SIP message could not be handled, bad request: 501f11182f3fb3a3-20956@172.28.128.100 [Sep 1 20:53:29] DEBUG[1321] chan_sip.c: Auto destroying SIP dialog '501f11182f3fb3a0-20956@172.28.128.100' [Sep 1 20:53:29] DEBUG[1321] chan_sip.c: Destroying SIP dialog 501f11182f3fb3a0-20956@172.28.128.100 [Sep 1 20:53:29] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '501f11182f3fb3a0-20956@172.28.128.100' Method: REGISTER [Sep 1 20:53:34] DEBUG[1298] res_pjsip_registrar.c: Woke up at 1599008014 Interval: 30 [Sep 1 20:53:34] DEBUG[1298] res_pjsip_registrar.c: Expiring 0 contacts [Sep 1 20:53:37] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKa61e.71a3c9d7000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-2cda CSeq: 10 REGISTER Call-ID: 501f11182f3fb3a4-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 <-------------> [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKa61e.71a3c9d7000000000000000000000000.0 [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-2cda [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 10 REGISTER [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a4-20956@172.28.128.100 [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:37] VERBOSE[1321] chan_sip.c: --- (11 headers 0 lines) --- [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a4-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-2cda --To-tag [Sep 1 20:53:37] DEBUG[1321] acl.c: For destination '172.28.128.100', our source address is '172.28.128.20'. [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:53:37] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:37] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:37] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 501f11182f3fb3a4-20956@172.28.128.100 - REGISTER (No RTP) [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a4-20956@172.28.128.100 [Sep 1 20:53:37] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:37] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:37] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:37] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:37] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:37] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKa61e.71a3c9d7000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-2cda To: ;tag=as68ca0f24 Call-ID: 501f11182f3fb3a4-20956@172.28.128.100 CSeq: 10 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="55a80811" Content-Length: 0 <------------> [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:37] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a4-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:37] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKb61e.ee5d8c90000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-2cda CSeq: 11 REGISTER Call-ID: 501f11182f3fb3a4-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 Authorization: Digest username="sbc", realm="asterisk", nonce="55a80811", uri="sip:172.28.128.20", response="7868295ab68cc7f7c6fcec02bbb39f03", algorithm=MD5 <-------------> [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKb61e.ee5d8c90000000000000000000000000.0 [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-2cda [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 11 REGISTER [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a4-20956@172.28.128.100 [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Header 11 [157]: Authorization: Digest username="sbc", realm="asterisk", nonce="55a80811", uri="sip:172.28.128.20", response="7868295ab68cc7f7c6fcec02bbb39f03", algorithm=MD5 [Sep 1 20:53:37] VERBOSE[1321] chan_sip.c: --- (12 headers 0 lines) --- [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a4-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-2cda --To-tag [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a4-20956@172.28.128.100 [Sep 1 20:53:37] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:37] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:37] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:37] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:37] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:37] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKb61e.ee5d8c90000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-2cda To: ;tag=as68ca0f24 Call-ID: 501f11182f3fb3a4-20956@172.28.128.100 CSeq: 11 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:37] NOTICE[1321] chan_sip.c: Registration from '' failed for '172.28.128.100:5060' - Wrong password [Sep 1 20:53:37] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a4-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:37] DEBUG[1321] chan_sip.c: SIP message could not be handled, bad request: 501f11182f3fb3a4-20956@172.28.128.100 [Sep 1 20:53:39] DEBUG[1321] chan_sip.c: Auto destroying SIP dialog '501f11182f3fb3a1-20956@172.28.128.100' [Sep 1 20:53:39] DEBUG[1321] chan_sip.c: Destroying SIP dialog 501f11182f3fb3a1-20956@172.28.128.100 [Sep 1 20:53:39] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '501f11182f3fb3a1-20956@172.28.128.100' Method: REGISTER [Sep 1 20:53:47] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKb61e.e54ee967000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f940 CSeq: 10 REGISTER Call-ID: 501f11182f3fb3a5-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 <-------------> [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKb61e.e54ee967000000000000000000000000.0 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f940 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 10 REGISTER [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a5-20956@172.28.128.100 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:47] VERBOSE[1321] chan_sip.c: --- (11 headers 0 lines) --- [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a5-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-f940 --To-tag [Sep 1 20:53:47] DEBUG[1321] acl.c: For destination '172.28.128.100', our source address is '172.28.128.20'. [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:53:47] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:47] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:47] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 501f11182f3fb3a5-20956@172.28.128.100 - REGISTER (No RTP) [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a5-20956@172.28.128.100 [Sep 1 20:53:47] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:47] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:47] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:47] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:47] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:47] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKb61e.e54ee967000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f940 To: ;tag=as5206350a Call-ID: 501f11182f3fb3a5-20956@172.28.128.100 CSeq: 10 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="3eac891e" Content-Length: 0 <------------> [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:47] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a5-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:47] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKc61e.b025e6e7000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f940 CSeq: 11 REGISTER Call-ID: 501f11182f3fb3a5-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 Authorization: Digest username="sbc", realm="asterisk", nonce="3eac891e", uri="sip:172.28.128.20", response="ecce21c7bc11d665a32f99206188369c", algorithm=MD5 <-------------> [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKc61e.b025e6e7000000000000000000000000.0 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f940 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 11 REGISTER [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a5-20956@172.28.128.100 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Header 11 [157]: Authorization: Digest username="sbc", realm="asterisk", nonce="3eac891e", uri="sip:172.28.128.20", response="ecce21c7bc11d665a32f99206188369c", algorithm=MD5 [Sep 1 20:53:47] VERBOSE[1321] chan_sip.c: --- (12 headers 0 lines) --- [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a5-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-f940 --To-tag [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a5-20956@172.28.128.100 [Sep 1 20:53:47] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:47] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:47] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:47] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:47] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:47] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bKc61e.b025e6e7000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-f940 To: ;tag=as5206350a Call-ID: 501f11182f3fb3a5-20956@172.28.128.100 CSeq: 11 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:47] NOTICE[1321] chan_sip.c: Registration from '' failed for '172.28.128.100:5060' - Wrong password [Sep 1 20:53:47] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a5-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:47] DEBUG[1321] chan_sip.c: SIP message could not be handled, bad request: 501f11182f3fb3a5-20956@172.28.128.100 [Sep 1 20:53:49] DEBUG[1321] chan_sip.c: Auto destroying SIP dialog '501f11182f3fb3a2-20956@172.28.128.100' [Sep 1 20:53:49] DEBUG[1321] chan_sip.c: Destroying SIP dialog 501f11182f3fb3a2-20956@172.28.128.100 [Sep 1 20:53:49] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '501f11182f3fb3a2-20956@172.28.128.100' Method: REGISTER [Sep 1 20:53:57] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bK861e.12a3a726000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-967f CSeq: 10 REGISTER Call-ID: 501f11182f3fb3a6-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 <-------------> [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bK861e.12a3a726000000000000000000000000.0 [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-967f [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 10 REGISTER [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a6-20956@172.28.128.100 [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:57] VERBOSE[1321] chan_sip.c: --- (11 headers 0 lines) --- [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a6-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-967f --To-tag [Sep 1 20:53:57] DEBUG[1321] acl.c: For destination '172.28.128.100', our source address is '172.28.128.20'. [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Setting AST_TRANSPORT_UDP with address 172.28.128.20:5060 [Sep 1 20:53:57] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:57] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:57] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Allocating new SIP dialog for 501f11182f3fb3a6-20956@172.28.128.100 - REGISTER (No RTP) [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a6-20956@172.28.128.100 [Sep 1 20:53:57] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:57] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:57] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:57] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:57] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:57] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bK861e.12a3a726000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-967f To: ;tag=as7b7e4003 Call-ID: 501f11182f3fb3a6-20956@172.28.128.100 CSeq: 10 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="22b42dd4" Content-Length: 0 <------------> [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:57] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a6-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:57] VERBOSE[1321] chan_sip.c: <--- SIP read from UDP:172.28.128.100:5060 ---> REGISTER sip:172.28.128.20 SIP/2.0 Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bK961e.2aa50be5000000000000000000000000.0 To: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-967f CSeq: 11 REGISTER Call-ID: 501f11182f3fb3a6-20956@172.28.128.100 Max-Forwards: 70 Content-Length: 0 User-Agent: ipSCAPE SBC Contact: Expires: 600 Authorization: Digest username="sbc", realm="asterisk", nonce="22b42dd4", uri="sip:172.28.128.20", response="87f024c15de17d9a49727eeb7f8fb30a", algorithm=MD5 <-------------> [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 0 [ 34]: REGISTER sip:172.28.128.20 SIP/2.0 [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 1 [ 85]: Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bK961e.2aa50be5000000000000000000000000.0 [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 2 [ 27]: To: [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 3 [ 71]: From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-967f [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 4 [ 17]: CSeq: 11 REGISTER [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 5 [ 46]: Call-ID: 501f11182f3fb3a6-20956@172.28.128.100 [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 8 [ 23]: User-Agent: ipSCAPE SBC [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 9 [ 39]: Contact: [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 10 [ 12]: Expires: 600 [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Header 11 [157]: Authorization: Digest username="sbc", realm="asterisk", nonce="22b42dd4", uri="sip:172.28.128.20", response="87f024c15de17d9a49727eeb7f8fb30a", algorithm=MD5 [Sep 1 20:53:57] VERBOSE[1321] chan_sip.c: --- (12 headers 0 lines) --- [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: = Looking for Call ID: 501f11182f3fb3a6-20956@172.28.128.100 (Checking From) --From tag 0dc875b7df224f2941db3e8443e3a1b7-967f --To-tag [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Initializing initreq for method REGISTER - callid 501f11182f3fb3a6-20956@172.28.128.100 [Sep 1 20:53:57] DEBUG[1321] netsock2.c: Splitting '172.28.128.100' into... [Sep 1 20:53:57] DEBUG[1321] netsock2.c: ...host '172.28.128.100' and port ''. [Sep 1 20:53:57] VERBOSE[1321] chan_sip.c: Sending to 172.28.128.100:5060 (no NAT) [Sep 1 20:53:57] DEBUG[1321] netsock2.c: Splitting '172.28.128.20' into... [Sep 1 20:53:57] DEBUG[1321] netsock2.c: ...host '172.28.128.20' and port ''. [Sep 1 20:53:57] VERBOSE[1321] chan_sip.c: <--- Transmitting (no NAT) to 172.28.128.100:5060 ---> SIP/2.0 403 Forbidden Via: SIP/2.0/UDP 172.28.128.100;branch=z9hG4bK961e.2aa50be5000000000000000000000000.0;received=172.28.128.100 From: ;tag=0dc875b7df224f2941db3e8443e3a1b7-967f To: ;tag=as7b7e4003 Call-ID: 501f11182f3fb3a6-20956@172.28.128.100 CSeq: 11 REGISTER Server: Asterisk PBX 16.8.0.ips Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE Supported: replaces, timer Content-Length: 0 <------------> [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: Trying to put 'SIP/2.0 403' onto UDP socket destined for 172.28.128.100:5060 [Sep 1 20:53:57] NOTICE[1321] chan_sip.c: Registration from '' failed for '172.28.128.100:5060' - Wrong password [Sep 1 20:53:57] VERBOSE[1321] chan_sip.c: Scheduling destruction of SIP dialog '501f11182f3fb3a6-20956@172.28.128.100' in 32000 ms (Method: REGISTER) [Sep 1 20:53:57] DEBUG[1321] chan_sip.c: SIP message could not be handled, bad request: 501f11182f3fb3a6-20956@172.28.128.100 [Sep 1 20:53:59] DEBUG[1321] chan_sip.c: Auto destroying SIP dialog '501f11182f3fb3a3-20956@172.28.128.100' [Sep 1 20:53:59] DEBUG[1321] chan_sip.c: Destroying SIP dialog 501f11182f3fb3a3-20956@172.28.128.100 [Sep 1 20:53:59] VERBOSE[1321] chan_sip.c: Really destroying SIP dialog '501f11182f3fb3a3-20956@172.28.128.100' Method: REGISTER [Sep 1 20:54:04] DEBUG[1298] res_pjsip_registrar.c: Woke up at 1599008044 Interval: 30 [Sep 1 20:54:04] DEBUG[1298] res_pjsip_registrar.c: Expiring 0 contacts