[Dec 2 13:08:49] VERBOSE[1091] config.c: == Parsing '/etc/asterisk/logger.conf': [Dec 2 13:08:49] DEBUG[1091] config.c: Parsing /etc/asterisk/logger.conf [Dec 2 13:08:49] VERBOSE[1091] config.c: == Found [Dec 2 13:08:49] VERBOSE[1091] logger.c: Asterisk Queue Logger restarted [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> REGISTER sip:asterisk SIP/2.0 Via: SIP/2.0/UDP 95.134.27.62:52643;branch=z9hG4bK00c02b1a1a1be1119399005056c00008;rport From: "PhonerLite" ;tag=1213372151 To: "PhonerLite" Call-ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.1.121 CSeq: 1 REGISTER Contact: ;+sip.instance="" Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE Max-Forwards: 70 User-Agent: SIPPER for PhonerLite Expires: 900 Content-Length: 0 <-------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 0 [ 29]: REGISTER sip:asterisk SIP/2.0 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 95.134.27.62:52643;branch=z9hG4bK00c02b1a1a1be1119399005056c00008;rport [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=1213372151 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 3 [ 37]: To: "PhonerLite" [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 4 [ 59]: Call-ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.1.121 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 5 [ 16]: CSeq: 1 REGISTER [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 6 [103]: Contact: ;+sip.instance="" [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 7 [ 71]: Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 8 [ 16]: Max-Forwards: 70 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 9 [ 33]: User-Agent: SIPPER for PhonerLite [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 10 [ 12]: Expires: 900 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: --- (12 headers 0 lines) --- [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: = Looking for Call ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.1.121 (Checking From) --From tag 1213372151 --To-tag [Dec 2 13:10:18] DEBUG[1081] acl.c: For destination '95.134.27.62', our source address is '95.167.155.190'. [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 95.167.155.190:5060 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Allocating new SIP dialog for 0093FA18-1A1B-E111-9398-005056C00008@192.168.1.121 - REGISTER (No RTP) [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Initializing initreq for method REGISTER - callid 0093FA18-1A1B-E111-9398-005056C00008@192.168.1.121 [Dec 2 13:10:18] DEBUG[1081] netsock2.c: Splitting '95.134.27.62:52643' into... [Dec 2 13:10:18] DEBUG[1081] netsock2.c: ...host '95.134.27.62' and port '52643'. [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Sending to 95.134.27.62:52643 (no NAT) [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 95.134.27.62:52643;branch=z9hG4bK00c02b1a1a1be1119399005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=1213372151 To: "PhonerLite" ;tag=as745ec765 Call-ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.1.121 CSeq: 1 REGISTER Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="4fae2449" Content-Length: 0 <------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Scheduling destruction of SIP dialog '0093FA18-1A1B-E111-9398-005056C00008@192.168.1.121' in 32000 ms (Method: REGISTER) [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> SUBSCRIBE sip:00002@asterisk SIP/2.0 Via: SIP/2.0/UDP 95.134.27.62:52643;branch=z9hG4bK00c02b1a1a1be111939a005056c00008;rport From: "PhonerLite" ;tag=1317709350 To: Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 CSeq: 2 SUBSCRIBE Contact: ;+sip.instance="" Max-Forwards: 70 User-Agent: SIPPER for PhonerLite Expires: 1800 Event: message-summary Accept: application/simple-message-summary Content-Length: 0 <-------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 0 [ 36]: SUBSCRIBE sip:00002@asterisk SIP/2.0 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 95.134.27.62:52643;branch=z9hG4bK00c02b1a1a1be111939a005056c00008;rport [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=1317709350 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 3 [ 24]: To: [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 4 [ 59]: Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 5 [ 17]: CSeq: 2 SUBSCRIBE [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 6 [103]: Contact: ;+sip.instance="" [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 8 [ 33]: User-Agent: SIPPER for PhonerLite [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 9 [ 13]: Expires: 1800 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 10 [ 22]: Event: message-summary [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 11 [ 42]: Accept: application/simple-message-summary [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: --- (13 headers 0 lines) --- [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: = Looking for Call ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 (Checking From) --From tag 1317709350 --To-tag [Dec 2 13:10:18] DEBUG[1081] acl.c: For destination '95.134.27.62', our source address is '95.167.155.190'. [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 95.167.155.190:5060 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Allocating new SIP dialog for 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 - SUBSCRIBE (No RTP) [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Creating new subscription [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Initializing initreq for method SUBSCRIBE - callid 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 [Dec 2 13:10:18] DEBUG[1081] netsock2.c: Splitting '95.134.27.62:52643' into... [Dec 2 13:10:18] DEBUG[1081] netsock2.c: ...host '95.134.27.62' and port '52643'. [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Sending to 95.134.27.62:52643 (no NAT) [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: build_route: Contact hop: ;+sip.instance="" [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: list_route: hop: [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Found peer '00002' for '00002' from 95.134.27.62:52643 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 95.134.27.62:52643;branch=z9hG4bK00c02b1a1a1be111939a005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=1317709350 To: ;tag=as4842a64d Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 CSeq: 2 SUBSCRIBE Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="4e7f4361" Content-Length: 0 <------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Scheduling destruction of SIP dialog '0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121' in 32000 ms (Method: SUBSCRIBE) [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> SUBSCRIBE sip:00002@asterisk SIP/2.0 Via: SIP/2.0/UDP 95.134.27.62:52643;branch=z9hG4bK00c02b1a1a1be111939b005056c00008;rport From: "PhonerLite" ;tag=1317709350 To: Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 CSeq: 3 SUBSCRIBE Contact: ;+sip.instance="" Max-Forwards: 70 User-Agent: SIPPER for PhonerLite Expires: 1800 Event: message-summary Accept: application/simple-message-summary Content-Length: 0 <-------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 0 [ 36]: SUBSCRIBE sip:00002@asterisk SIP/2.0 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 95.134.27.62:52643;branch=z9hG4bK00c02b1a1a1be111939b005056c00008;rport [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=1317709350 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 3 [ 24]: To: [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 4 [ 59]: Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 5 [ 17]: CSeq: 3 SUBSCRIBE [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 6 [103]: Contact: ;+sip.instance="" [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 8 [ 33]: User-Agent: SIPPER for PhonerLite [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 9 [ 13]: Expires: 1800 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 10 [ 22]: Event: message-summary [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 11 [ 42]: Accept: application/simple-message-summary [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: --- (13 headers 0 lines) --- [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: = Looking for Call ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 (Checking From) --From tag 1317709350 --To-tag [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Got a new subscription 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 (possibly with auth) or retransmission [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Creating new subscription [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Initializing initreq for method SUBSCRIBE - callid 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 [Dec 2 13:10:18] DEBUG[1081] netsock2.c: Splitting '95.134.27.62:52643' into... [Dec 2 13:10:18] DEBUG[1081] netsock2.c: ...host '95.134.27.62' and port '52643'. [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Sending to 95.134.27.62:52643 (NAT) [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: build_route: Retaining previous route: [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Found peer '00002' for '00002' from 95.134.27.62:52643 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 95.134.27.62:52643;branch=z9hG4bK00c02b1a1a1be111939b005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=1317709350 To: ;tag=as4842a64d Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 CSeq: 3 SUBSCRIBE Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="0db22feb" Content-Length: 0 <------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Scheduling destruction of SIP dialog '0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121' in 32000 ms (Method: SUBSCRIBE) [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> REGISTER sip:asterisk SIP/2.0 Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939c005056c00008;rport From: "PhonerLite" ;tag=1213372151 To: "PhonerLite" Call-ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 CSeq: 4 REGISTER Contact: ;+sip.instance="" Authorization: Digest username="00002", realm="asterisk", nonce="4fae2449", uri="sip:asterisk", response="41eff96f3068e2fff3deff04dd898bcf", algorithm=MD5 Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE Max-Forwards: 70 User-Agent: SIPPER for PhonerLite Expires: 900 Content-Length: 0 <-------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 0 [ 29]: REGISTER sip:asterisk SIP/2.0 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939c005056c00008;rport [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=1213372151 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 3 [ 37]: To: "PhonerLite" [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 4 [ 58]: Call-ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 5 [ 16]: CSeq: 4 REGISTER [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 6 [103]: Contact: ;+sip.instance="" [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 7 [154]: Authorization: Digest username="00002", realm="asterisk", nonce="4fae2449", uri="sip:asterisk", response="41eff96f3068e2fff3deff04dd898bcf", algorithm=MD5 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 8 [ 71]: Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 10 [ 33]: User-Agent: SIPPER for PhonerLite [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 11 [ 12]: Expires: 900 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: --- (13 headers 0 lines) --- [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: = Looking for Call ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 (Checking From) --From tag 1213372151 --To-tag [Dec 2 13:10:18] DEBUG[1081] acl.c: For destination '95.134.27.62', our source address is '95.167.155.190'. [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 95.167.155.190:5060 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Allocating new SIP dialog for 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 - REGISTER (No RTP) [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Initializing initreq for method REGISTER - callid 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 [Dec 2 13:10:18] DEBUG[1081] netsock2.c: Splitting '192.168.88.1:52643' into... [Dec 2 13:10:18] DEBUG[1081] netsock2.c: ...host '192.168.88.1' and port '52643'. [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Sending to 95.134.27.62:52643 (no NAT) [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939c005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=1213372151 To: "PhonerLite" ;tag=as2c66a9f7 Call-ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 CSeq: 4 REGISTER Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="0ee2ad52" Content-Length: 0 <------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Scheduling destruction of SIP dialog '0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1' in 32000 ms (Method: REGISTER) [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> SUBSCRIBE sip:00002@asterisk SIP/2.0 Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939d005056c00008;rport From: "PhonerLite" ;tag=1317709350 To: Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 CSeq: 5 SUBSCRIBE Contact: ;+sip.instance="" Authorization: Digest username="00002", realm="asterisk", nonce="4e7f4361", uri="sip:00002@asterisk", response="102492e94f5c61e99d09e520063006c8", algorithm=MD5 Max-Forwards: 70 User-Agent: SIPPER for PhonerLite Expires: 1800 Event: message-summary Accept: application/simple-message-summary Content-Length: 0 <-------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 0 [ 36]: SUBSCRIBE sip:00002@asterisk SIP/2.0 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939d005056c00008;rport [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=1317709350 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 3 [ 24]: To: [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 4 [ 58]: Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 5 [ 17]: CSeq: 5 SUBSCRIBE [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 6 [103]: Contact: ;+sip.instance="" [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 7 [160]: Authorization: Digest username="00002", realm="asterisk", nonce="4e7f4361", uri="sip:00002@asterisk", response="102492e94f5c61e99d09e520063006c8", algorithm=MD5 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 8 [ 16]: Max-Forwards: 70 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 9 [ 33]: User-Agent: SIPPER for PhonerLite [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 10 [ 13]: Expires: 1800 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 11 [ 22]: Event: message-summary [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 12 [ 42]: Accept: application/simple-message-summary [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: --- (14 headers 0 lines) --- [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: = Looking for Call ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 (Checking From) --From tag 1317709350 --To-tag [Dec 2 13:10:18] DEBUG[1081] acl.c: For destination '95.134.27.62', our source address is '95.167.155.190'. [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 95.167.155.190:5060 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Allocating new SIP dialog for 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 - SUBSCRIBE (No RTP) [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Creating new subscription [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Initializing initreq for method SUBSCRIBE - callid 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 [Dec 2 13:10:18] DEBUG[1081] netsock2.c: Splitting '192.168.88.1:52643' into... [Dec 2 13:10:18] DEBUG[1081] netsock2.c: ...host '192.168.88.1' and port '52643'. [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Sending to 95.134.27.62:52643 (no NAT) [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: build_route: Contact hop: ;+sip.instance="" [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: list_route: hop: [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Found peer '00002' for '00002' from 95.134.27.62:52643 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939d005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=1317709350 To: ;tag=as7ac7f8d1 Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 CSeq: 5 SUBSCRIBE Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="24654d48" Content-Length: 0 <------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Scheduling destruction of SIP dialog '0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1' in 32000 ms (Method: SUBSCRIBE) [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> SUBSCRIBE sip:00002@asterisk SIP/2.0 Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939e005056c00008;rport From: "PhonerLite" ;tag=1317709350 To: Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 CSeq: 6 SUBSCRIBE Contact: ;+sip.instance="" Authorization: Digest username="00002", realm="asterisk", nonce="0db22feb", uri="sip:00002@asterisk", response="fb682a19f5d817a3c8444b09e9de6179", algorithm=MD5 Max-Forwards: 70 User-Agent: SIPPER for PhonerLite Expires: 1800 Event: message-summary Accept: application/simple-message-summary Content-Length: 0 <-------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 0 [ 36]: SUBSCRIBE sip:00002@asterisk SIP/2.0 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939e005056c00008;rport [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=1317709350 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 3 [ 24]: To: [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 4 [ 58]: Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 5 [ 17]: CSeq: 6 SUBSCRIBE [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 6 [103]: Contact: ;+sip.instance="" [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 7 [160]: Authorization: Digest username="00002", realm="asterisk", nonce="0db22feb", uri="sip:00002@asterisk", response="fb682a19f5d817a3c8444b09e9de6179", algorithm=MD5 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 8 [ 16]: Max-Forwards: 70 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 9 [ 33]: User-Agent: SIPPER for PhonerLite [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 10 [ 13]: Expires: 1800 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 11 [ 22]: Event: message-summary [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 12 [ 42]: Accept: application/simple-message-summary [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: --- (14 headers 0 lines) --- [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: = Looking for Call ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 (Checking From) --From tag 1317709350 --To-tag [Dec 2 13:10:18] DEBUG[1081] netsock2.c: Splitting 'asterisk' into... [Dec 2 13:10:18] DEBUG[1081] netsock2.c: ...host 'asterisk' and port ''. [Dec 2 13:10:18] DEBUG[1081] netsock2.c: Splitting 'asterisk' into... [Dec 2 13:10:18] DEBUG[1081] netsock2.c: ...host 'asterisk' and port ''. [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Got a new subscription 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 (possibly with auth) or retransmission [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Creating new subscription [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Initializing initreq for method SUBSCRIBE - callid 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 [Dec 2 13:10:18] DEBUG[1081] netsock2.c: Splitting '192.168.88.1:52643' into... [Dec 2 13:10:18] DEBUG[1081] netsock2.c: ...host '192.168.88.1' and port '52643'. [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Sending to 95.134.27.62:52643 (NAT) [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: build_route: Retaining previous route: [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Found peer '00002' for '00002' from 95.134.27.62:52643 [Dec 2 13:10:18] NOTICE[1081] chan_sip.c: Correct auth, but based on stale nonce received from '"PhonerLite" ;tag=1317709350' [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939e005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=1317709350 To: ;tag=as7ac7f8d1 Call-ID: 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 CSeq: 6 SUBSCRIBE Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="24654d48", stale=true Content-Length: 0 <------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Scheduling destruction of SIP dialog '0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1' in 32000 ms (Method: SUBSCRIBE) [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> REGISTER sip:asterisk SIP/2.0 Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939f005056c00008;rport From: "PhonerLite" ;tag=1213372151 To: "PhonerLite" Call-ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 CSeq: 7 REGISTER Contact: ;+sip.instance="" Authorization: Digest username="00002", realm="asterisk", nonce="0ee2ad52", uri="sip:asterisk", response="969be8d4334e7e6ef19b5bc8db8d08a2", algorithm=MD5 Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE Max-Forwards: 70 User-Agent: SIPPER for PhonerLite Expires: 900 Content-Length: 0 <-------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 0 [ 29]: REGISTER sip:asterisk SIP/2.0 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939f005056c00008;rport [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=1213372151 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 3 [ 37]: To: "PhonerLite" [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 4 [ 58]: Call-ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 5 [ 16]: CSeq: 7 REGISTER [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 6 [103]: Contact: ;+sip.instance="" [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 7 [154]: Authorization: Digest username="00002", realm="asterisk", nonce="0ee2ad52", uri="sip:asterisk", response="969be8d4334e7e6ef19b5bc8db8d08a2", algorithm=MD5 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 8 [ 71]: Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 10 [ 33]: User-Agent: SIPPER for PhonerLite [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 11 [ 12]: Expires: 900 [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: --- (13 headers 0 lines) --- [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: = Looking for Call ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 (Checking From) --From tag 1213372151 --To-tag [Dec 2 13:10:18] DEBUG[1081] netsock2.c: Splitting 'asterisk' into... [Dec 2 13:10:18] DEBUG[1081] netsock2.c: ...host 'asterisk' and port ''. [Dec 2 13:10:18] DEBUG[1081] netsock2.c: Splitting 'asterisk' into... [Dec 2 13:10:18] DEBUG[1081] netsock2.c: ...host 'asterisk' and port ''. [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Initializing initreq for method REGISTER - callid 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 [Dec 2 13:10:18] DEBUG[1081] netsock2.c: Splitting '192.168.88.1:52643' into... [Dec 2 13:10:18] DEBUG[1081] netsock2.c: ...host '192.168.88.1' and port '52643'. [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Sending to 95.134.27.62:52643 (NAT) [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Store REGISTER's src-IP:port for call routing. [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: -- Registered SIP '00002' at 95.134.27.62:52643 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: > Saved useragent "SIPPER for PhonerLite" for peer 00002 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: <--- Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00c02b1a1a1be111939f005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=1213372151 To: "PhonerLite" ;tag=as2c66a9f7 Call-ID: 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 CSeq: 7 REGISTER Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Expires: 900 Contact: ;expires=900 Date: Fri, 02 Dec 2011 10:10:18 GMT Content-Length: 0 <------------> [Dec 2 13:10:18] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:10:18] VERBOSE[1081] chan_sip.c: Scheduling destruction of SIP dialog '0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1' in 32000 ms (Method: REGISTER) [Dec 2 13:10:18] DEBUG[1070] devicestate.c: No provider found, checking channel drivers for SIP - 00002 [Dec 2 13:10:18] DEBUG[1070] chan_sip.c: Checking device state for peer 00002 [Dec 2 13:10:18] DEBUG[1070] devicestate.c: Changing state for SIP/00002 - state 1 (Not in use) [Dec 2 13:10:18] DEBUG[1070] devicestate.c: device 'SIP/00002' state '1' [Dec 2 13:10:18] DEBUG[1088] app_queue.c: Device 'SIP/00002' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Auto destroying SIP dialog '0093FA18-1A1B-E111-9398-005056C00008@192.168.1.121' [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Destroying SIP dialog 0093FA18-1A1B-E111-9398-005056C00008@192.168.1.121 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Really destroying SIP dialog '0093FA18-1A1B-E111-9398-005056C00008@192.168.1.121' Method: REGISTER [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Auto destroying SIP dialog '0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121' [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Destroying SIP dialog 0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Really destroying SIP dialog '0093FA18-1A1B-E111-9399-005056C00008@192.168.1.121' Method: SUBSCRIBE [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> INVITE sip:74957410001@asterisk SIP/2.0 Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a0005056c00008;rport From: "PhonerLite" ;tag=2100474174 To: Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 CSeq: 8 INVITE Contact: Content-Type: application/sdp Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE Max-Forwards: 70 Supported: 100rel, replaces, from-change User-Agent: SIPPER for PhonerLite P-Preferred-Identity: Content-Length: 410 v=0 o=- 2509404189 0 IN IP4 95.134.27.62 s=SIPPER for PhonerLite c=IN IP4 95.134.27.62 t=0 0 m=audio 52645 RTP/AVP 8 0 2 3 97 110 111 9 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=rtpmap:110 speex/8000 a=rtpmap:111 speex/16000 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtcp:52648 a=sendrecv <-------------> [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 0 [ 39]: INVITE sip:74957410001@asterisk SIP/2.0 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a0005056c00008;rport [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=2100474174 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 3 [ 30]: To: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 4 [ 58]: Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 5 [ 14]: CSeq: 8 INVITE [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 6 [ 39]: Contact: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 7 [ 29]: Content-Type: application/sdp [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 8 [ 71]: Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 10 [ 40]: Supported: 100rel, replaces, from-change [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 11 [ 33]: User-Agent: SIPPER for PhonerLite [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 12 [ 42]: P-Preferred-Identity: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 13 [ 19]: Content-Length: 410 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 14 [ 0]: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 0 [ 3]: v=0 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 1 [ 36]: o=- 2509404189 0 IN IP4 95.134.27.62 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 2 [ 23]: s=SIPPER for PhonerLite [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 3 [ 21]: c=IN IP4 95.134.27.62 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 4 [ 5]: t=0 0 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 5 [ 46]: m=audio 52645 RTP/AVP 8 0 2 3 97 110 111 9 101 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 8 [ 23]: a=rtpmap:2 G726-32/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 9 [ 19]: a=rtpmap:3 GSM/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 10 [ 21]: a=rtpmap:97 iLBC/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 11 [ 23]: a=rtpmap:110 speex/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 12 [ 24]: a=rtpmap:111 speex/16000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 13 [ 20]: a=rtpmap:9 G722/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 14 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 15 [ 15]: a=fmtp:101 0-16 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 16 [ 12]: a=rtcp:52648 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 17 [ 10]: a=sendrecv [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: --- (14 headers 18 lines) --- [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: = Looking for Call ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 (Checking From) --From tag 2100474174 --To-tag [Dec 2 13:10:50] DEBUG[1081] acl.c: For destination '95.134.27.62', our source address is '95.167.155.190'. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 95.167.155.190:5060 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Allocating new SIP dialog for 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 - INVITE (No RTP) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Dec 2 13:10:50] DEBUG[1081] sip/reqresp_parser.c: Begin: parsing SIP "Supported: 100rel, replaces, from-change" [Dec 2 13:10:50] DEBUG[1081] sip/reqresp_parser.c: Found SIP option: -100rel- [Dec 2 13:10:50] DEBUG[1081] sip/reqresp_parser.c: Matched SIP option: 100rel [Dec 2 13:10:50] DEBUG[1081] sip/reqresp_parser.c: Found SIP option: -replaces- [Dec 2 13:10:50] DEBUG[1081] sip/reqresp_parser.c: Matched SIP option: replaces [Dec 2 13:10:50] DEBUG[1081] sip/reqresp_parser.c: Found SIP option: -from-change- [Dec 2 13:10:50] DEBUG[1081] sip/reqresp_parser.c: Matched SIP option: from-change [Dec 2 13:10:50] DEBUG[1081] netsock2.c: Splitting '192.168.88.1:52643' into... [Dec 2 13:10:50] DEBUG[1081] netsock2.c: ...host '192.168.88.1' and port '52643'. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Sending to 95.134.27.62:52643 (no NAT) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Initializing initreq for method INVITE - callid 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Using INVITE request as basis request - 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found peer '00002' for '00002' from 95.134.27.62:52643 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: <--- Reliably Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a0005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=2100474174 To: ;tag=as6c689d2d Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 CSeq: 8 INVITE Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="2d66625b" Content-Length: 0 <------------> [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #12 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Scheduling destruction of SIP dialog '00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1' in 32000 ms (Method: INVITE) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Auto destroying SIP dialog '0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1' [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Destroying SIP dialog 0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Really destroying SIP dialog '0093FA18-1A1B-E111-9399-005056C00008@192.168.88.1' Method: SUBSCRIBE [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> ACK sip:74957410001@asterisk SIP/2.0 Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a0005056c00008;rport From: "PhonerLite" ;tag=2100474174 To: ;tag=as6c689d2d Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 CSeq: 8 ACK Max-Forwards: 70 Content-Length: 0 <-------------> [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 0 [ 36]: ACK sip:74957410001@asterisk SIP/2.0 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a0005056c00008;rport [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=2100474174 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 3 [ 45]: To: ;tag=as6c689d2d [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 4 [ 58]: Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 5 [ 11]: CSeq: 8 ACK [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: --- (8 headers 0 lines) --- [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: = Looking for Call ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 (Checking From) --From tag 2100474174 --To-tag as6c689d2d [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #12 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Stopping retransmission on '00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1' of Response 8: Match Found [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> INVITE sip:74957410001@asterisk SIP/2.0 Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a1005056c00008;rport From: "PhonerLite" ;tag=2100474174 To: Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 CSeq: 9 INVITE Contact: Authorization: Digest username="00002", realm="asterisk", nonce="2d66625b", uri="sip:74957410001@asterisk", response="9a664139657b7fe692e378ad95fd53ca", algorithm=MD5 Content-Type: application/sdp Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE Max-Forwards: 70 Supported: 100rel, replaces, from-change User-Agent: SIPPER for PhonerLite P-Preferred-Identity: Content-Length: 410 v=0 o=- 2509404189 0 IN IP4 95.134.27.62 s=SIPPER for PhonerLite c=IN IP4 95.134.27.62 t=0 0 m=audio 52645 RTP/AVP 8 0 2 3 97 110 111 9 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=rtpmap:110 speex/8000 a=rtpmap:111 speex/16000 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtcp:52648 a=sendrecv <-------------> [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 0 [ 39]: INVITE sip:74957410001@asterisk SIP/2.0 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a1005056c00008;rport [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=2100474174 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 3 [ 30]: To: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 4 [ 58]: Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 5 [ 14]: CSeq: 9 INVITE [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 6 [ 39]: Contact: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 7 [166]: Authorization: Digest username="00002", realm="asterisk", nonce="2d66625b", uri="sip:74957410001@asterisk", response="9a664139657b7fe692e378ad95fd53ca", algorithm=MD5 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 8 [ 29]: Content-Type: application/sdp [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 9 [ 71]: Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 10 [ 16]: Max-Forwards: 70 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 11 [ 40]: Supported: 100rel, replaces, from-change [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 12 [ 33]: User-Agent: SIPPER for PhonerLite [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 13 [ 42]: P-Preferred-Identity: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 14 [ 19]: Content-Length: 410 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 15 [ 0]: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 0 [ 3]: v=0 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 1 [ 36]: o=- 2509404189 0 IN IP4 95.134.27.62 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 2 [ 23]: s=SIPPER for PhonerLite [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 3 [ 21]: c=IN IP4 95.134.27.62 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 4 [ 5]: t=0 0 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 5 [ 46]: m=audio 52645 RTP/AVP 8 0 2 3 97 110 111 9 101 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 8 [ 23]: a=rtpmap:2 G726-32/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 9 [ 19]: a=rtpmap:3 GSM/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 10 [ 21]: a=rtpmap:97 iLBC/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 11 [ 23]: a=rtpmap:110 speex/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 12 [ 24]: a=rtpmap:111 speex/16000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 13 [ 20]: a=rtpmap:9 G722/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 14 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 15 [ 15]: a=fmtp:101 0-16 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 16 [ 12]: a=rtcp:52648 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 17 [ 10]: a=sendrecv [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: --- (15 headers 18 lines) --- [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: = Looking for Call ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 (Checking From) --From tag 2100474174 --To-tag [Dec 2 13:10:50] DEBUG[1081] netsock2.c: Splitting 'asterisk' into... [Dec 2 13:10:50] DEBUG[1081] netsock2.c: ...host 'asterisk' and port ''. [Dec 2 13:10:50] DEBUG[1081] netsock2.c: Splitting 'asterisk' into... [Dec 2 13:10:50] DEBUG[1081] netsock2.c: ...host 'asterisk' and port ''. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Dec 2 13:10:50] DEBUG[1081] netsock2.c: Splitting '192.168.88.1:52643' into... [Dec 2 13:10:50] DEBUG[1081] netsock2.c: ...host '192.168.88.1' and port '52643'. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Sending to 95.134.27.62:52643 (NAT) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Initializing initreq for method INVITE - callid 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Using INVITE request as basis request - 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found peer '00002' for '00002' from 95.134.27.62:52643 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x917f9c0' [Dec 2 13:10:50] DEBUG[1081] res_rtp_asterisk.c: Allocated port 15850 for RTP instance '0x917f9c0' [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: RTP instance '0x917f9c0' is setup and ready to go [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x91813c0' [Dec 2 13:10:50] DEBUG[1081] res_rtp_asterisk.c: Allocated port 12880 for RTP instance '0x91813c0' [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: RTP instance '0x91813c0' is setup and ready to go [Dec 2 13:10:50] DEBUG[1081] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x91813c0' [Dec 2 13:10:50] DEBUG[1081] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x917f9c0' [Dec 2 13:10:50] VERBOSE[1081] netsock2.c: == Using SIP RTP CoS mark 5 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Setting NAT on RTP to On [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Setting NAT on TRTP to On [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing session-level SDP o=- 2509404189 0 IN IP4 95.134.27.62... UNSUPPORTED. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing session-level SDP s=SIPPER for PhonerLite... UNSUPPORTED. [Dec 2 13:10:50] DEBUG[1081] netsock2.c: Splitting '95.134.27.62' into... [Dec 2 13:10:50] DEBUG[1081] netsock2.c: ...host '95.134.27.62' and port ''. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing session-level SDP c=IN IP4 95.134.27.62... OK. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found RTP audio format 8 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Setting payload 8 based on m type on 0xb7ade380 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found RTP audio format 0 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Setting payload 0 based on m type on 0xb7ade380 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found RTP audio format 2 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found RTP audio format 3 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Setting payload 3 based on m type on 0xb7ade380 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found RTP audio format 97 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Setting payload 97 based on m type on 0xb7ade380 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found RTP audio format 110 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Setting payload 110 based on m type on 0xb7ade380 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found RTP audio format 111 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Setting payload 111 based on m type on 0xb7ade380 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found RTP audio format 9 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Setting payload 9 based on m type on 0xb7ade380 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found RTP audio format 101 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Setting payload 101 based on m type on 0xb7ade380 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found audio description format PCMA for ID 8 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found audio description format PCMU for ID 0 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found audio description format G726-32 for ID 2 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:2 G726-32/8000... OK. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found audio description format GSM for ID 3 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found audio description format iLBC for ID 97 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:97 iLBC/8000... OK. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found audio description format speex for ID 110 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:110 speex/8000... OK. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found audio description format speex for ID 111 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:111 speex/16000... OK. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found audio description format G722 for ID 9 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found audio description format telephone-event for ID 101 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtcp:52648... UNSUPPORTED. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Incorporating payload 0 on 0xb7ade380 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Incorporating payload 2 on 0xb7ade380 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Incorporating payload 3 on 0xb7ade380 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Incorporating payload 8 on 0xb7ade380 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Incorporating payload 9 on 0xb7ade380 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Incorporating payload 97 on 0xb7ade380 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Incorporating payload 101 on 0xb7ade380 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Incorporating payload 110 on 0xb7ade380 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Incorporating payload 111 on 0xb7ade380 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Capabilities: us - 0x10c (ulaw|alaw|g729), peer - audio=0x200001e0e (gsm|ulaw|alaw|g726|speex|speex16|ilbc|g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Dec 2 13:10:50] DEBUG[1081] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x917f9c0' [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Peer audio RTP is at port 95.134.27.62:52645 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Copying payload 0 from 0xb7ade380 to 0x917fb6c [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Copying payload 2 from 0xb7ade380 to 0x917fb6c [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Copying payload 3 from 0xb7ade380 to 0x917fb6c [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Copying payload 8 from 0xb7ade380 to 0x917fb6c [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Copying payload 9 from 0xb7ade380 to 0x917fb6c [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Copying payload 97 from 0xb7ade380 to 0x917fb6c [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Copying payload 101 from 0xb7ade380 to 0x917fb6c [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Copying payload 110 from 0xb7ade380 to 0x917fb6c [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Copying payload 111 from 0xb7ade380 to 0x917fb6c [Dec 2 13:10:50] DEBUG[1081] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x91813c0' [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Peer doesn't provide T.140 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Checking SIP call limits for device 00002 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Updating call counter for incoming call [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Looking for 74957410001 in test (domain asterisk) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: *** Our native formats are 0x8 (alaw) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: *** Our capabilities are 0x10c (ulaw|alaw|g729) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: This channel will not be able to handle video. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: build_route: Contact hop: [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: list_route: hop: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: SIP/00002-00000000: New call is still down.... Trying... [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: <--- Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a1005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=2100474174 To: Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 CSeq: 9 INVITE Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:10:50] DEBUG[1070] devicestate.c: No provider found, checking channel drivers for SIP - 00002 [Dec 2 13:10:50] DEBUG[1070] chan_sip.c: Checking device state for peer 00002 [Dec 2 13:10:50] DEBUG[1070] devicestate.c: Changing state for SIP/00002 - state 1 (Not in use) [Dec 2 13:10:50] DEBUG[1070] devicestate.c: device 'SIP/00002' state '1' [Dec 2 13:10:50] DEBUG[1103] pbx.c: Result of 'EXTEN' is '74957410001' [Dec 2 13:10:50] DEBUG[1103] pbx.c: Launching 'Dial' [Dec 2 13:10:50] VERBOSE[1103] pbx.c: -- Executing [74957410001@test:1] Dial("SIP/00002-00000000", "SIP/ez/01#74957410001") in new stack [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Asked to create a SIP channel with formats: 0x8 (alaw) [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Allocating new SIP dialog for 6c770ea56653371519c30447192d9437@127.0.0.1:0 - INVITE (No RTP) [Dec 2 13:10:50] DEBUG[1103] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x9191280' [Dec 2 13:10:50] DEBUG[1103] res_rtp_asterisk.c: Allocated port 17624 for RTP instance '0x9191280' [Dec 2 13:10:50] DEBUG[1103] rtp_engine.c: RTP instance '0x9191280' is setup and ready to go [Dec 2 13:10:50] DEBUG[1103] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x9191280' [Dec 2 13:10:50] VERBOSE[1103] netsock2.c: == Using SIP RTP CoS mark 5 [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Setting NAT on RTP to Off [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Dec 2 13:10:50] DEBUG[1103] acl.c: For destination '80.239.155.9', our source address is '95.167.155.190'. [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 95.167.155.190:5060 [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: *** Our native formats are 0x8 (alaw) [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: *** Our capabilities are 0x10c (ulaw|alaw|g729) [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: This channel will not be able to handle video. [Dec 2 13:10:50] DEBUG[1103] rtp_engine.c: Seeded SDP of 'SIP/ez-00000001' with that of 'SIP/00002-00000000' [Dec 2 13:10:50] DEBUG[1103] channel.c: Not copying variable DIALEDTIME. [Dec 2 13:10:50] DEBUG[1103] channel.c: Not copying variable ANSWEREDTIME. [Dec 2 13:10:50] DEBUG[1103] channel.c: Not copying variable DIALEDPEERNAME. [Dec 2 13:10:50] DEBUG[1103] channel.c: Not copying variable DIALEDPEERNUMBER. [Dec 2 13:10:50] DEBUG[1103] channel.c: Not copying variable DIALSTATUS. [Dec 2 13:10:50] DEBUG[1103] channel.c: Not copying variable SIPCALLID. [Dec 2 13:10:50] DEBUG[1103] channel.c: Not copying variable SIPDOMAIN. [Dec 2 13:10:50] DEBUG[1103] channel.c: Not copying variable SIPURI. [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Outgoing Call for 01#74957410001 [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Updating call counter for outgoing call [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: False Text flag: False [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Dec 2 13:10:50] VERBOSE[1103] chan_sip.c: Audio is at 5060 [Dec 2 13:10:50] VERBOSE[1103] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Dec 2 13:10:50] VERBOSE[1103] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Dec 2 13:10:50] VERBOSE[1103] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: -- Done with adding codecs to SDP [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Initializing initreq for method INVITE - callid 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 0 [ 46]: INVITE sip:01#74957410001@80.239.155.9 SIP/2.0 [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 95.167.155.190:5060;branch=z9hG4bK25fd7643 [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 3 [ 60]: From: "PhonerLite" ;tag=as1dc742c6 [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 4 [ 37]: To: [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 5 [ 40]: Contact: [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 6 [ 61]: Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 8 [ 32]: User-Agent: Asterisk PBX 1.8.7.1 [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 9 [ 35]: Date: Fri, 02 Dec 2011 10:10:50 GMT [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Dec 2 13:10:50] VERBOSE[1103] chan_sip.c: Reliably Transmitting (no NAT) to 80.239.155.9:5060: INVITE sip:01#74957410001@80.239.155.9 SIP/2.0 Via: SIP/2.0/UDP 95.167.155.190:5060;branch=z9hG4bK25fd7643 Max-Forwards: 70 From: "PhonerLite" ;tag=as1dc742c6 To: Contact: Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.8.7.1 Date: Fri, 02 Dec 2011 10:10:50 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 264 v=0 o=root 1027058667 1027058667 IN IP4 95.167.155.190 s=Asterisk PBX 1.8.7.1 c=IN IP4 95.167.155.190 t=0 0 m=audio 17624 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=ptime:20 a=sendrecv --- [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #15 [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 80.239.155.9:5060 [Dec 2 13:10:50] VERBOSE[1103] app_dial.c: -- Called SIP/ez/01#74957410001 [Dec 2 13:10:50] DEBUG[1088] app_queue.c: Device 'SIP/00002' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Auto destroying SIP dialog '0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1' [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Destroying SIP dialog 0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Really destroying SIP dialog '0093FA18-1A1B-E111-9398-005056C00008@192.168.88.1' Method: REGISTER [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:80.239.155.9:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 95.167.155.190:5060;branch=z9hG4bK25fd7643 From: "PhonerLite" ;tag=as1dc742c6 To: Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 CSeq: 102 INVITE Contact: Server: MERA MVTS3G v.4.3.0-46 Content-Length: 0 <-------------> [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 95.167.155.190:5060;branch=z9hG4bK25fd7643 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 2 [ 60]: From: "PhonerLite" ;tag=as1dc742c6 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 3 [ 37]: To: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 4 [ 61]: Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 6 [ 47]: Contact: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 7 [ 30]: Server: MERA MVTS3G v.4.3.0-46 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: --- (9 headers 0 lines) --- [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: = Looking for Call ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 (Checking To) --From tag as1dc742c6 --To-tag [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: *** SIP TIMER: Cancelling retransmission #15 - INVITE (got response) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060' Request 102: Found [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: SIP response 100 to standard invite [Dec 2 13:10:50] DEBUG[1103] res_rtp_asterisk.c: Got RTCP report of 56 bytes [Dec 2 13:10:50] DEBUG[1103] res_rtp_asterisk.c: RTCP Read too short [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:80.239.155.9:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 95.167.155.190:5060;branch=z9hG4bK25fd7643 From: "PhonerLite" ;tag=as1dc742c6 To: ;tag=1677808505-3776031516-453006246-406678561 Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 CSeq: 102 INVITE Contact: Content-Type: application/sdp Server: MERA MVTS3G v.4.3.0-46 Content-Length: 241 v=0 o=- 1322806304 1322806304 IN IP4 80.239.155.9 s=- c=IN IP4 80.239.155.9 t=0 0 m=audio 16786 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv a=silenceSupp:off - - - - <-------------> [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 95.167.155.190:5060;branch=z9hG4bK25fd7643 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 2 [ 60]: From: "PhonerLite" ;tag=as1dc742c6 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 3 [ 83]: To: ;tag=1677808505-3776031516-453006246-406678561 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 4 [ 61]: Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 6 [ 47]: Contact: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 7 [ 29]: Content-Type: application/sdp [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 8 [ 30]: Server: MERA MVTS3G v.4.3.0-46 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 9 [ 19]: Content-Length: 241 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 10 [ 0]: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 0 [ 3]: v=0 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 1 [ 45]: o=- 1322806304 1322806304 IN IP4 80.239.155.9 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 2 [ 3]: s=- [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 3 [ 21]: c=IN IP4 80.239.155.9 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 4 [ 5]: t=0 0 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 5 [ 27]: m=audio 16786 RTP/AVP 8 101 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 10 [ 10]: a=sendrecv [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: --- (10 headers 12 lines) --- [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: = Looking for Call ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 (Checking To) --From tag as1dc742c6 --To-tag 1677808505-3776031516-453006246-406678561 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060' Request 102: Found [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: SIP response 180 to standard invite [Dec 2 13:10:50] DEBUG[1070] devicestate.c: No provider found, checking channel drivers for SIP - ez [Dec 2 13:10:50] DEBUG[1070] chan_sip.c: Checking device state for peer ez [Dec 2 13:10:50] DEBUG[1070] devicestate.c: Changing state for SIP/ez - state 1 (Not in use) [Dec 2 13:10:50] DEBUG[1070] devicestate.c: device 'SIP/ez' state '1' [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing session-level SDP o=- 1322806304 1322806304 IN IP4 80.239.155.9... UNSUPPORTED. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing session-level SDP s=-... UNSUPPORTED. [Dec 2 13:10:50] DEBUG[1081] netsock2.c: Splitting '80.239.155.9' into... [Dec 2 13:10:50] DEBUG[1081] netsock2.c: ...host '80.239.155.9' and port ''. [Dec 2 13:10:50] DEBUG[1088] app_queue.c: Device 'SIP/ez' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing session-level SDP c=IN IP4 80.239.155.9... OK. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found RTP audio format 8 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Setting payload 8 based on m type on 0xb7addff0 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found RTP audio format 101 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Setting payload 101 based on m type on 0xb7addff0 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found audio description format PCMA for ID 8 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Found audio description format telephone-event for ID 101 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED. [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Incorporating payload 8 on 0xb7addff0 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Incorporating payload 101 on 0xb7addff0 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Capabilities: us - 0x10c (ulaw|alaw|g729), peer - audio=0x8 (alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw) [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Dec 2 13:10:50] DEBUG[1081] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9191280' [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: Peer audio RTP is at port 80.239.155.9:16786 [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Copying payload 8 from 0xb7addff0 to 0x919142c [Dec 2 13:10:50] DEBUG[1081] rtp_engine.c: Copying payload 101 from 0xb7addff0 to 0x919142c [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: We have an owner, now see if we need to change this call [Dec 2 13:10:50] VERBOSE[1103] app_dial.c: -- SIP/ez-00000001 is ringing [Dec 2 13:10:50] DEBUG[1103] rtp_engine.c: Setting early bridge SDP of 'SIP/00002-00000000' with that of 'SIP/ez-00000001' [Dec 2 13:10:50] VERBOSE[1103] chan_sip.c: <--- Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a1005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=2100474174 To: ;tag=as6ace5eef Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 CSeq: 9 INVITE Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:10:50] VERBOSE[1103] app_dial.c: -- SIP/ez-00000001 is making progress passing it to SIP/00002-00000000 [Dec 2 13:10:50] DEBUG[1103] rtp_engine.c: Setting early bridge SDP of 'SIP/00002-00000000' with that of 'SIP/ez-00000001' [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Setting framing from config on incoming call [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Dec 2 13:10:50] VERBOSE[1103] chan_sip.c: Audio is at 5060 [Dec 2 13:10:50] VERBOSE[1103] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Dec 2 13:10:50] VERBOSE[1103] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Dec 2 13:10:50] VERBOSE[1103] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: -- Done with adding codecs to SDP [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Dec 2 13:10:50] VERBOSE[1103] chan_sip.c: <--- Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a1005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=2100474174 To: ;tag=as6ace5eef Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 CSeq: 9 INVITE Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 264 v=0 o=root 1172915733 1172915733 IN IP4 95.167.155.190 s=Asterisk PBX 1.8.7.1 c=IN IP4 95.167.155.190 t=0 0 m=audio 15850 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=ptime:20 a=sendrecv <------------> [Dec 2 13:10:50] DEBUG[1103] chan_sip.c: Trying to put 'SIP/2.0 183' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:80.239.155.9:5060 ---> OPTIONS sip:00002@95.167.155.190:5060 SIP/2.0 Via: SIP/2.0/UDP 80.239.155.9:5060;rport;branch=z9hG4bK-2330033785-3776031516-453031846-4066785611 Via: SIP/2.0/UDP 80.239.155.9:5061;rport=5061;branch=z9hG4bK-2330033785-3776031516-453031846-406678561;received=80.239.155.9 From: ;tag=1677808505-3776031516-453006246-406678561 To: "PhonerLite" ;tag=as1dc742c6 Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 CSeq: 103 OPTIONS Contact: Allow: ACK, BYE, CANCEL, INFO, INVITE, OPTIONS, PRACK, REFER, REGISTER, UPDATE Accept: application/dtmf-relay Accept: application/isup Accept: application/sdp Supported: 100rel Max-Forwards: 70 User-Agent: MERA MVTS3G v.4.3.0-46 Content-Length: 0 <-------------> [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 0 [ 45]: OPTIONS sip:00002@95.167.155.190:5060 SIP/2.0 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 1 [ 98]: Via: SIP/2.0/UDP 80.239.155.9:5060;rport;branch=z9hG4bK-2330033785-3776031516-453031846-4066785611 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 2 [124]: Via: SIP/2.0/UDP 80.239.155.9:5061;rport=5061;branch=z9hG4bK-2330033785-3776031516-453031846-406678561;received=80.239.155.9 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 3 [ 85]: From: ;tag=1677808505-3776031516-453006246-406678561 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 4 [ 58]: To: "PhonerLite" ;tag=as1dc742c6 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 5 [ 61]: Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 6 [ 17]: CSeq: 103 OPTIONS [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 7 [ 47]: Contact: [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 8 [ 78]: Allow: ACK, BYE, CANCEL, INFO, INVITE, OPTIONS, PRACK, REFER, REGISTER, UPDATE [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 9 [ 30]: Accept: application/dtmf-relay [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 10 [ 24]: Accept: application/isup [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 11 [ 23]: Accept: application/sdp [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 12 [ 17]: Supported: 100rel [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 13 [ 16]: Max-Forwards: 70 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 14 [ 34]: User-Agent: MERA MVTS3G v.4.3.0-46 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Header 15 [ 17]: Content-Length: 0 [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: --- (16 headers 0 lines) --- [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: = Looking for Call ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 (Checking From) --From tag 1677808505-3776031516-453006246-406678561 --To-tag as1dc742c6 [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Dec 2 13:10:50] VERBOSE[1081] chan_sip.c: <--- Transmitting (no NAT) to 80.239.155.9:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 80.239.155.9:5060;rport;branch=z9hG4bK-2330033785-3776031516-453031846-4066785611;received=80.239.155.9 Via: SIP/2.0/UDP 80.239.155.9:5061;rport=5061;branch=z9hG4bK-2330033785-3776031516-453031846-406678561;received=80.239.155.9 From: ;tag=1677808505-3776031516-453006246-406678561 To: "PhonerLite" ;tag=as1dc742c6 Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 CSeq: 103 OPTIONS Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Accept: application/sdp Content-Length: 0 <------------> [Dec 2 13:10:50] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 80.239.155.9:5060 [Dec 2 13:10:50] DEBUG[1103] res_rtp_asterisk.c: RTCP NAT: Got RTCP from other end. Now sending to address 95.134.27.62:52648 [Dec 2 13:10:50] DEBUG[1103] res_rtp_asterisk.c: Got RTCP report of 28 bytes [Dec 2 13:10:50] DEBUG[1103] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw [Dec 2 13:10:50] DEBUG[1103] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160 [Dec 2 13:10:50] DEBUG[1103] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x9191280' [Dec 2 13:10:51] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:80.239.155.9:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 95.167.155.190:5060;branch=z9hG4bK25fd7643 From: "PhonerLite" ;tag=as1dc742c6 To: ;tag=1677808505-3776031516-453006246-406678561 Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 CSeq: 102 INVITE Contact: Content-Type: application/sdp Allow: ACK, BYE, CANCEL, INFO, INVITE, OPTIONS, REFER, REGISTER, UPDATE Server: MERA MVTS3G v.4.3.0-46 X-mera-expires: 86460 Content-Length: 241 v=0 o=- 1322806304 1322806304 IN IP4 80.239.155.9 s=- c=IN IP4 80.239.155.9 t=0 0 m=audio 16786 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv a=silenceSupp:off - - - - <-------------> [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 95.167.155.190:5060;branch=z9hG4bK25fd7643 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 2 [ 60]: From: "PhonerLite" ;tag=as1dc742c6 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 3 [ 83]: To: ;tag=1677808505-3776031516-453006246-406678561 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 4 [ 61]: Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 6 [ 47]: Contact: [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 7 [ 29]: Content-Type: application/sdp [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 8 [ 71]: Allow: ACK, BYE, CANCEL, INFO, INVITE, OPTIONS, REFER, REGISTER, UPDATE [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 9 [ 30]: Server: MERA MVTS3G v.4.3.0-46 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 10 [ 21]: X-mera-expires: 86460 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 11 [ 19]: Content-Length: 241 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 12 [ 0]: [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 0 [ 3]: v=0 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 1 [ 45]: o=- 1322806304 1322806304 IN IP4 80.239.155.9 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 2 [ 3]: s=- [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 3 [ 21]: c=IN IP4 80.239.155.9 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 4 [ 5]: t=0 0 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 5 [ 27]: m=audio 16786 RTP/AVP 8 101 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 10 [ 10]: a=sendrecv [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [Dec 2 13:10:51] VERBOSE[1081] chan_sip.c: --- (12 headers 12 lines) --- [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: = Looking for Call ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 (Checking To) --From tag as1dc742c6 --To-tag 1677808505-3776031516-453006246-406678561 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Acked pending invite 102 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Stopping retransmission on '555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060' of Request 102: Match Found [Dec 2 13:10:51] NOTICE[1081] chan_sip.c: Peer 'ez' is now Lagged. (1ms / 0ms) [Dec 2 13:10:51] DEBUG[1070] devicestate.c: No provider found, checking channel drivers for SIP - ez [Dec 2 13:10:51] DEBUG[1070] chan_sip.c: Checking device state for peer ez [Dec 2 13:10:51] DEBUG[1070] devicestate.c: Changing state for SIP/ez - state 1 (Not in use) [Dec 2 13:10:51] DEBUG[1070] devicestate.c: device 'SIP/ez' state '1' [Dec 2 13:10:51] DEBUG[1088] app_queue.c: Device 'SIP/ez' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 2 13:10:51] DEBUG[1103] res_rtp_asterisk.c: Ooh, format changed from unknown to alaw [Dec 2 13:10:51] DEBUG[1103] res_rtp_asterisk.c: Created smoother: format: alaw ms: 20 len: 160 [Dec 2 13:10:51] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:80.239.155.9:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 95.167.155.190:5060;branch=z9hG4bK25fd7643 From: "PhonerLite" ;tag=as1dc742c6 To: ;tag=1677808505-3776031516-453006246-406678561 Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 CSeq: 102 INVITE Contact: Content-Type: application/sdp Allow: ACK, BYE, CANCEL, INFO, INVITE, OPTIONS, REFER, REGISTER, UPDATE Server: MERA MVTS3G v.4.3.0-46 X-mera-expires: 86460 Content-Length: 241 v=0 o=- 1322806304 1322806304 IN IP4 80.239.155.9 s=- c=IN IP4 80.239.155.9 t=0 0 m=audio 16786 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv a=silenceSupp:off - - - - <-------------> [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 95.167.155.190:5060;branch=z9hG4bK25fd7643 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 2 [ 60]: From: "PhonerLite" ;tag=as1dc742c6 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 3 [ 83]: To: ;tag=1677808505-3776031516-453006246-406678561 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 4 [ 61]: Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 6 [ 47]: Contact: [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 7 [ 29]: Content-Type: application/sdp [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 8 [ 71]: Allow: ACK, BYE, CANCEL, INFO, INVITE, OPTIONS, REFER, REGISTER, UPDATE [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 9 [ 30]: Server: MERA MVTS3G v.4.3.0-46 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 10 [ 21]: X-mera-expires: 86460 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 11 [ 19]: Content-Length: 241 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Header 12 [ 0]: [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 0 [ 3]: v=0 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 1 [ 45]: o=- 1322806304 1322806304 IN IP4 80.239.155.9 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 2 [ 3]: s=- [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 3 [ 21]: c=IN IP4 80.239.155.9 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 4 [ 5]: t=0 0 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 5 [ 27]: m=audio 16786 RTP/AVP 8 101 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 7 [ 33]: a=rtpmap:101 telephone-event/8000 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 10 [ 10]: a=sendrecv [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [Dec 2 13:10:51] VERBOSE[1081] chan_sip.c: --- (12 headers 12 lines) --- [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: = Looking for Call ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 (Checking To) --From tag as1dc742c6 --To-tag 1677808505-3776031516-453006246-406678561 [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Stopping retransmission on '555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060' of Request 102: Match Not Found [Dec 2 13:10:51] VERBOSE[1081] chan_sip.c: Transmitting (no NAT) to 80.239.155.9:5060: ACK sip:01#74957410001@80.239.155.9 SIP/2.0 Via: SIP/2.0/UDP 95.167.155.190:5060;branch=z9hG4bK38686679 Max-Forwards: 70 From: "PhonerLite" ;tag=as1dc742c6 To: ;tag=1677808505-3776031516-453006246-406678561 Contact: Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 CSeq: 102 ACK User-Agent: Asterisk PBX 1.8.7.1 Content-Length: 0 --- [Dec 2 13:10:51] DEBUG[1081] chan_sip.c: Trying to put 'ACK sip:01#' onto UDP socket destined for 80.239.155.9:5060 [Dec 2 13:10:55] DEBUG[1103] res_rtp_asterisk.c: Got RTCP report of 80 bytes [Dec 2 13:10:57] DEBUG[1103] res_rtp_asterisk.c: Got RTCP report of 52 bytes [Dec 2 13:11:00] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> CANCEL sip:74957410001@asterisk SIP/2.0 Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a1005056c00008;rport From: "PhonerLite" ;tag=2100474174 To: Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 CSeq: 9 CANCEL Authorization: Digest username="00002", realm="asterisk", nonce="2d66625b", uri="sip:74957410001@asterisk", response="299d741d6a18e2e896028567e8f9e141", algorithm=MD5 Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE Max-Forwards: 70 User-Agent: SIPPER for PhonerLite Content-Length: 0 <-------------> [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 0 [ 39]: CANCEL sip:74957410001@asterisk SIP/2.0 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a1005056c00008;rport [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=2100474174 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 3 [ 30]: To: [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 4 [ 58]: Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 5 [ 14]: CSeq: 9 CANCEL [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 6 [166]: Authorization: Digest username="00002", realm="asterisk", nonce="2d66625b", uri="sip:74957410001@asterisk", response="299d741d6a18e2e896028567e8f9e141", algorithm=MD5 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 7 [ 71]: Allow: INVITE, OPTIONS, ACK, BYE, CANCEL, INFO, NOTIFY, MESSAGE, UPDATE [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 8 [ 16]: Max-Forwards: 70 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 9 [ 33]: User-Agent: SIPPER for PhonerLite [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Dec 2 13:11:00] VERBOSE[1081] chan_sip.c: --- (11 headers 0 lines) --- [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: = Looking for Call ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 (Checking From) --From tag 2100474174 --To-tag [Dec 2 13:11:00] DEBUG[1081] netsock2.c: Splitting 'asterisk' into... [Dec 2 13:11:00] DEBUG[1081] netsock2.c: ...host 'asterisk' and port ''. [Dec 2 13:11:00] DEBUG[1081] netsock2.c: Splitting 'asterisk' into... [Dec 2 13:11:00] DEBUG[1081] netsock2.c: ...host 'asterisk' and port ''. [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: **** Received CANCEL (14) - Command in SIP CANCEL [Dec 2 13:11:00] DEBUG[1081] netsock2.c: Splitting '192.168.88.1:52643' into... [Dec 2 13:11:00] DEBUG[1081] netsock2.c: ...host '192.168.88.1' and port '52643'. [Dec 2 13:11:00] VERBOSE[1081] chan_sip.c: Sending to 95.134.27.62:52643 (NAT) [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Setting SIP_ALREADYGONE on dialog 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 [Dec 2 13:11:00] DEBUG[1081] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x917f9c0' [Dec 2 13:11:00] DEBUG[1081] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x91813c0' [Dec 2 13:11:00] VERBOSE[1081] chan_sip.c: <--- Reliably Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a1005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=2100474174 To: ;tag=as6ace5eef Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 CSeq: 9 INVITE Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #22 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 487' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:11:00] VERBOSE[1081] chan_sip.c: <--- Transmitting (NAT) to 95.134.27.62:52643 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a1005056c00008;received=95.134.27.62;rport=52643 From: "PhonerLite" ;tag=2100474174 To: ;tag=as6ace5eef Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 CSeq: 9 CANCEL Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 95.134.27.62:52643 [Dec 2 13:11:00] DEBUG[1103] channel.c: Hanging up channel 'SIP/ez-00000001' [Dec 2 13:11:00] DEBUG[1103] chan_sip.c: Hanging up zombie call. Be scared. [Dec 2 13:11:00] DEBUG[1103] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x9191280' [Dec 2 13:11:00] VERBOSE[1103] chan_sip.c: Scheduling destruction of SIP dialog '555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060' in 32000 ms (Method: OPTIONS) [Dec 2 13:11:00] DEBUG[1103] app_dial.c: Exiting with DIALSTATUS=CANCEL. [Dec 2 13:11:00] DEBUG[1070] devicestate.c: No provider found, checking channel drivers for SIP - ez [Dec 2 13:11:00] DEBUG[1103] pbx.c: Spawn extension (test,74957410001,1) exited non-zero on 'SIP/00002-00000000' [Dec 2 13:11:00] DEBUG[1070] chan_sip.c: Checking device state for peer ez [Dec 2 13:11:00] DEBUG[1070] devicestate.c: Changing state for SIP/ez - state 1 (Not in use) [Dec 2 13:11:00] DEBUG[1070] devicestate.c: device 'SIP/ez' state '1' [Dec 2 13:11:00] VERBOSE[1103] pbx.c: == Spawn extension (test, 74957410001, 1) exited non-zero on 'SIP/00002-00000000' [Dec 2 13:11:00] DEBUG[1103] channel.c: Soft-Hanging up channel 'SIP/00002-00000000' [Dec 2 13:11:00] DEBUG[1103] channel.c: Hanging up channel 'SIP/00002-00000000' [Dec 2 13:11:00] DEBUG[1103] chan_sip.c: Hanging up zombie call. Be scared. [Dec 2 13:11:00] DEBUG[1103] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x917f9c0' [Dec 2 13:11:00] DEBUG[1103] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x91813c0' [Dec 2 13:11:00] DEBUG[1070] devicestate.c: No provider found, checking channel drivers for SIP - 00002 [Dec 2 13:11:00] DEBUG[1070] chan_sip.c: Checking device state for peer 00002 [Dec 2 13:11:00] DEBUG[1070] devicestate.c: Changing state for SIP/00002 - state 1 (Not in use) [Dec 2 13:11:00] DEBUG[1070] devicestate.c: device 'SIP/00002' state '1' [Dec 2 13:11:00] DEBUG[1088] app_queue.c: Device 'SIP/ez' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 2 13:11:00] DEBUG[1088] app_queue.c: Device 'SIP/00002' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Dec 2 13:11:00] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:95.134.27.62:52643 ---> ACK sip:74957410001@asterisk SIP/2.0 Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a1005056c00008;rport From: "PhonerLite" ;tag=2100474174 To: ;tag=as6ace5eef Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 CSeq: 9 ACK Authorization: Digest username="00002", realm="asterisk", nonce="2d66625b", uri="sip:74957410001@asterisk", response="9a664139657b7fe692e378ad95fd53ca", algorithm=MD5 Max-Forwards: 70 Content-Length: 0 <-------------> [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 0 [ 36]: ACK sip:74957410001@asterisk SIP/2.0 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 1 [ 88]: Via: SIP/2.0/UDP 192.168.88.1:52643;branch=z9hG4bK00903e2d1a1be11193a1005056c00008;rport [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 2 [ 54]: From: "PhonerLite" ;tag=2100474174 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 3 [ 45]: To: ;tag=as6ace5eef [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 4 [ 58]: Call-ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 5 [ 11]: CSeq: 9 ACK [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 6 [166]: Authorization: Digest username="00002", realm="asterisk", nonce="2d66625b", uri="sip:74957410001@asterisk", response="9a664139657b7fe692e378ad95fd53ca", algorithm=MD5 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Dec 2 13:11:00] VERBOSE[1081] chan_sip.c: --- (9 headers 0 lines) --- [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: = Looking for Call ID: 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 (Checking From) --From tag 2100474174 --To-tag as6ace5eef [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #22 [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Stopping retransmission on '00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1' of Response 9: Match Found [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Destroying SIP dialog 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 [Dec 2 13:11:00] VERBOSE[1081] chan_sip.c: Really destroying SIP dialog '555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060' Method: OPTIONS [Dec 2 13:11:00] DEBUG[1081] rtp_engine.c: Destroyed RTP instance '0x9191280' [Dec 2 13:11:00] DEBUG[1081] chan_sip.c: Destroying SIP dialog 00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1 [Dec 2 13:11:00] VERBOSE[1081] chan_sip.c: Really destroying SIP dialog '00903E2D-1A1B-E111-939F-005056C00008@192.168.88.1' Method: ACK [Dec 2 13:11:00] DEBUG[1081] rtp_engine.c: Destroyed RTP instance '0x917f9c0' [Dec 2 13:11:00] DEBUG[1081] rtp_engine.c: Destroyed RTP instance '0x91813c0' [Dec 2 13:11:11] VERBOSE[1081] chan_sip.c: <--- SIP read from UDP:80.239.155.9:5060 ---> BYE sip:00002@95.167.155.190:5060 SIP/2.0 Via: SIP/2.0/UDP 80.239.155.9:5060;rport;branch=z9hG4bK-1985061765-3776031516-453016971-4066785611 Via: SIP/2.0/UDP 80.239.155.9:5061;rport=5061;branch=z9hG4bK-1985061765-3776031516-453016971-406678561;received=80.239.155.9 From: ;tag=1677808505-3776031516-453006246-406678561 To: "PhonerLite" ;tag=as1dc742c6 Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 CSeq: 104 BYE Contact: Max-Forwards: 70 User-Agent: MERA MVTS3G v.4.3.0-46 Reason: MVTSLocal;cause=64;text="Rtp Timeout" Content-Length: 0 <-------------> [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 0 [ 41]: BYE sip:00002@95.167.155.190:5060 SIP/2.0 [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 1 [ 98]: Via: SIP/2.0/UDP 80.239.155.9:5060;rport;branch=z9hG4bK-1985061765-3776031516-453016971-4066785611 [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 2 [124]: Via: SIP/2.0/UDP 80.239.155.9:5061;rport=5061;branch=z9hG4bK-1985061765-3776031516-453016971-406678561;received=80.239.155.9 [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 3 [ 85]: From: ;tag=1677808505-3776031516-453006246-406678561 [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 4 [ 58]: To: "PhonerLite" ;tag=as1dc742c6 [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 5 [ 61]: Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 6 [ 13]: CSeq: 104 BYE [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 7 [ 47]: Contact: [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 8 [ 16]: Max-Forwards: 70 [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 9 [ 34]: User-Agent: MERA MVTS3G v.4.3.0-46 [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 10 [ 45]: Reason: MVTSLocal;cause=64;text="Rtp Timeout" [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Dec 2 13:11:11] VERBOSE[1081] chan_sip.c: --- (12 headers 0 lines) --- [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: = Looking for Call ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 (Checking From) --From tag 1677808505-3776031516-453006246-406678561 --To-tag as1dc742c6 [Dec 2 13:11:11] DEBUG[1081] acl.c: For destination '80.239.155.9', our source address is '95.167.155.190'. [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Setting SIP_TRANSPORT_UNKNOWN with address 95.167.155.190:5060 [Dec 2 13:11:11] VERBOSE[1081] chan_sip.c: <--- Transmitting (no NAT) to 80.239.155.9:5060 ---> SIP/2.0 481 Call leg/transaction does not exist Via: SIP/2.0/UDP 80.239.155.9:5060;rport;branch=z9hG4bK-1985061765-3776031516-453016971-4066785611;received=80.239.155.9 Via: SIP/2.0/UDP 80.239.155.9:5061;rport=5061;branch=z9hG4bK-1985061765-3776031516-453016971-406678561;received=80.239.155.9 From: ;tag=1677808505-3776031516-453006246-406678561 To: "PhonerLite" ;tag=as1dc742c6 Call-ID: 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 CSeq: 104 BYE Server: Asterisk PBX 1.8.7.1 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Trying to put 'SIP/2.0 481' onto UDP socket destined for 80.239.155.9:5060 [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: That's odd... Got a request in unknown dialog. Callid 555346511dd095e53c80dfcb0e3ed5bc@95.167.155.190:5060 [Dec 2 13:11:11] DEBUG[1081] chan_sip.c: Invalid SIP message - rejected , no callid, len 651