[Feb 4 00:39:28] Asterisk 11.7.0 built by root @ temp on a x86_64 running Linux on 2014-01-30 21:35:11 UTC [Feb 4 00:39:28] DEBUG[3186] config.c: Parsing /etc/asterisk/logger.conf [Feb 4 00:39:28] VERBOSE[3186] config.c: == Parsing '/etc/asterisk/logger.conf': Found [Feb 4 00:39:28] VERBOSE[3186] logger.c: Asterisk Queue Logger restarted [Feb 4 00:39:29] DEBUG[3187] chan_sip.c: = Looking for Call ID: 6874e7b7-1cfc-2c91-efd4-26f19543a8e3 (Checking From) --From tag pmLIwuah1uLPAZoZ2eAk --To-tag [Feb 4 00:39:29] DEBUG[3187] acl.c: For destination '2.2.2.2', our source address is '1.1.1.1'. [Feb 4 00:39:29] DEBUG[3187] chan_sip.c: Setting SIP_TRANSPORT_WS with address 1.1.1.1:5060 [Feb 4 00:39:32] DEBUG[3148] chan_sip.c: Checking device state for peer 1060 [Feb 4 00:39:32] DEBUG[3148] devicestate.c: Changing state for SIP/1060 - state 5 (Unavailable) [Feb 4 00:39:32] DEBUG[3148] devicestate.c: device 'SIP/1060' state '5' [Feb 4 00:39:32] DEBUG[3148] devicestate.c: No provider found, checking channel drivers for SIP - 1061 [Feb 4 00:39:32] DEBUG[3148] chan_sip.c: Checking device state for peer 1061 [Feb 4 00:39:32] DEBUG[3148] devicestate.c: Changing state for SIP/1061 - state 5 (Unavailable) [Feb 4 00:39:32] DEBUG[3148] devicestate.c: device 'SIP/1061' state '5' [Feb 4 00:39:32] DEBUG[3150] app_queue.c: Extension '1060@default' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Feb 4 00:39:32] DEBUG[3150] app_queue.c: Extension '1061@default' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Feb 4 00:39:32] DEBUG[3184] app_queue.c: Device 'SIP/1060' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Feb 4 00:39:32] DEBUG[3184] app_queue.c: Device 'SIP/1061' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Feb 4 00:40:12] DEBUG[4035] http.c: HTTP Request URI is /ws [Feb 4 00:40:12] DEBUG[4035] http.c: match request [ws] with handler [httpstatus] len 0 [Feb 4 00:40:12] DEBUG[4035] http.c: match request [ws] with handler [phoneprov] len 10 [Feb 4 00:40:12] DEBUG[4035] http.c: match request [ws] with handler [static] len 9 [Feb 4 00:40:12] DEBUG[4035] http.c: match request [ws] with handler [ws] len 6 [Feb 4 00:40:12] VERBOSE[4035] res_http_websocket.c: == WebSocket connection from '2.2.2.2:61080' for protocol 'sip' accepted using version '13' [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61080 ---> ˙REGISTER sip:1.1.1.1 SIP/2.0 ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKT9JWedOAW8gPpRFScZGu9qZAZf5m9feR;rport ˙From: "1061";tag=hKgSdtMeZkq47PNxTfRV ˙To: "1061" ˙Contact: "1061";expires=200;click2call=no;+g.oma.sip-im;+audio;language="en,fr" ˙Call-ID: b35bee67-3af1-a56a-05d0-54e9c96533d0 ˙CSeq: 62157 REGISTER ˙Content-Length: 0 ˙Route: ˙Max-Forwards: 70 ˙User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 ˙Organization: Doubango Telecom ˙Supported: path ˙ ˙<-------------> [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 0 [ 36]: REGISTER sip:1.1.1.1 SIP/2.0 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKT9JWedOAW8gPpRFScZGu9qZAZf5m9feR;rport [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 2 [ 63]: From: "1061";tag=hKgSdtMeZkq47PNxTfRV [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 3 [ 36]: To: "1061" [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 4 [144]: Contact: "1061";expires=200;click2call=no;+g.oma.sip-im;+audio;language="en,fr" [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 5 [ 45]: Call-ID: b35bee67-3af1-a56a-05d0-54e9c96533d0 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 6 [ 20]: CSeq: 62157 REGISTER [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 8 [ 66]: Route: [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 10 [ 49]: User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 11 [ 30]: Organization: Doubango Telecom [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 12 [ 15]: Supported: path [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: --- (13 headers 0 lines) --- [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: = Looking for Call ID: b35bee67-3af1-a56a-05d0-54e9c96533d0 (Checking From) --From tag hKgSdtMeZkq47PNxTfRV --To-tag [Feb 4 00:40:12] DEBUG[4035] acl.c: For destination '2.2.2.2', our source address is '1.1.1.1'. [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Setting SIP_TRANSPORT_WS with address 1.1.1.1:5060 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Allocating new SIP dialog for b35bee67-3af1-a56a-05d0-54e9c96533d0 - REGISTER (No RTP) [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Initializing initreq for method REGISTER - callid b35bee67-3af1-a56a-05d0-54e9c96533d0 [Feb 4 00:40:12] DEBUG[4035] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:12] DEBUG[4035] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: ˙<--- Transmitting (NAT) to 2.2.2.2:61080 ---> ˙SIP/2.0 401 Unauthorized ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKT9JWedOAW8gPpRFScZGu9qZAZf5m9feR;received=2.2.2.2;rport=61080 ˙From: "1061";tag=hKgSdtMeZkq47PNxTfRV ˙To: "1061";tag=as24385a40 ˙Call-ID: b35bee67-3af1-a56a-05d0-54e9c96533d0 ˙CSeq: 62157 REGISTER ˙Server: Asterisk PBX 11.7.0 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙WWW-Authenticate: Digest algorithm=MD5, realm="1.1.1.1", nonce="171b15fe" ˙Content-Length: 0 ˙ ˙ ˙<------------> [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Trying to put 'SIP/2.0 401' onto WS socket destined for 2.2.2.2:61080 [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: Scheduling destruction of SIP dialog 'b35bee67-3af1-a56a-05d0-54e9c96533d0' in 32000 ms (Method: REGISTER) [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61080 ---> ˙REGISTER sip:1.1.1.1 SIP/2.0 ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKTae7k8MWo2fM0LOo8I2zkxIa0pE4LtET;rport ˙From: "1061";tag=hKgSdtMeZkq47PNxTfRV ˙To: "1061" ˙Contact: "1061";expires=200;click2call=no;+g.oma.sip-im;+audio;language="en,fr" ˙Call-ID: b35bee67-3af1-a56a-05d0-54e9c96533d0 ˙CSeq: 62158 REGISTER ˙Content-Length: 0 ˙Route: ˙Max-Forwards: 70 ˙Authorization: Digest username="1061",realm="1.1.1.1",nonce="171b15fe",uri="sip:1.1.1.1",response="8226f121f4e585b7ee8ce2aa3a4c2bcd",algorithm=MD5 ˙User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 ˙Organization: Doubango Telecom ˙Supported: path ˙ ˙<-------------> [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 0 [ 36]: REGISTER sip:1.1.1.1 SIP/2.0 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKTae7k8MWo2fM0LOo8I2zkxIa0pE4LtET;rport [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 2 [ 63]: From: "1061";tag=hKgSdtMeZkq47PNxTfRV [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 3 [ 36]: To: "1061" [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 4 [144]: Contact: "1061";expires=200;click2call=no;+g.oma.sip-im;+audio;language="en,fr" [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 5 [ 45]: Call-ID: b35bee67-3af1-a56a-05d0-54e9c96533d0 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 6 [ 20]: CSeq: 62158 REGISTER [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 8 [ 66]: Route: [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 10 [162]: Authorization: Digest username="1061",realm="1.1.1.1",nonce="171b15fe",uri="sip:1.1.1.1",response="8226f121f4e585b7ee8ce2aa3a4c2bcd",algorithm=MD5 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 11 [ 49]: User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 12 [ 30]: Organization: Doubango Telecom [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 13 [ 15]: Supported: path [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: --- (14 headers 0 lines) --- [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: = Looking for Call ID: b35bee67-3af1-a56a-05d0-54e9c96533d0 (Checking From) --From tag hKgSdtMeZkq47PNxTfRV --To-tag [Feb 4 00:40:12] DEBUG[4035] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:12] DEBUG[4035] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:12] DEBUG[4035] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:12] DEBUG[4035] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Initializing initreq for method REGISTER - callid b35bee67-3af1-a56a-05d0-54e9c96533d0 [Feb 4 00:40:12] DEBUG[4035] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:12] DEBUG[4035] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: peer '1061' has contacted us over WS even though we prefer UDP. [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Store REGISTER's src-IP:port for call routing. [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: -- Registered SIP '1061' at 2.2.2.2:61080 [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: ˙<--- Transmitting (NAT) to 2.2.2.2:61080 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKTae7k8MWo2fM0LOo8I2zkxIa0pE4LtET;received=2.2.2.2;rport=61080 ˙From: "1061";tag=hKgSdtMeZkq47PNxTfRV ˙To: "1061";tag=as24385a40 ˙Call-ID: b35bee67-3af1-a56a-05d0-54e9c96533d0 ˙CSeq: 62158 REGISTER ˙Server: Asterisk PBX 11.7.0 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Expires: 200 ˙Contact: ;expires=200 ˙Date: Tue, 04 Feb 2014 05:40:12 GMT ˙Content-Length: 0 ˙ ˙ ˙<------------> [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Trying to put 'SIP/2.0 200' onto WS socket destined for 2.2.2.2:61080 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Allocating new SIP dialog for 0fbc6577277891c2184d202a33892253@[2001:4802:7801:103:3624:f793:ff20:14]:5060 - NOTIFY (No RTP) [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Feb 4 00:40:12] DEBUG[4035] acl.c: For destination '2.2.2.2', our source address is '1.1.1.1'. [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Setting SIP_TRANSPORT_WS with address 1.1.1.1:5060 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: SIP call-id changed from '0fbc6577277891c2184d202a33892253@[2001:4802:7801:103:3624:f793:ff20:14]:5060' to '7c64798f60f4f86c7df617af24f0ef0c@1.1.1.1:5060' [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: Scheduling destruction of SIP dialog '7c64798f60f4f86c7df617af24f0ef0c@1.1.1.1:5060' in 32000 ms (Method: NOTIFY) [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Initializing initreq for method NOTIFY - callid 7c64798f60f4f86c7df617af24f0ef0c@1.1.1.1:5060 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 0 [ 78]: NOTIFY sips:1061@df7jal23ls0d.invalid;rtcweb-breaker=yes;transport=wss SIP/2.0 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/WS 1.1.1.1:5060;branch=z9hG4bK0db41688;rport [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 3 [ 62]: From: "asterisk" ;tag=as79a688b9 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 4 [ 69]: To: [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 5 [ 57]: Contact: [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 6 [ 62]: Call-ID: 7c64798f60f4f86c7df617af24f0ef0c@1.1.1.1:5060 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 7 [ 16]: CSeq: 102 NOTIFY [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 8 [ 31]: User-Agent: Asterisk PBX 11.7.0 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 9 [ 22]: Event: message-summary [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 10 [ 48]: Content-Type: application/simple-message-summary [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: Reliably Transmitting (NAT) to 2.2.2.2:61080: ˙NOTIFY sips:1061@df7jal23ls0d.invalid;rtcweb-breaker=yes;transport=wss SIP/2.0 ˙Via: SIP/2.0/WS 1.1.1.1:5060;branch=z9hG4bK0db41688;rport ˙Max-Forwards: 70 ˙From: "asterisk" ;tag=as79a688b9 ˙To: ˙Contact: ˙Call-ID: 7c64798f60f4f86c7df617af24f0ef0c@1.1.1.1:5060 ˙CSeq: 102 NOTIFY ˙User-Agent: Asterisk PBX 11.7.0 ˙Event: message-summary ˙Content-Type: application/simple-message-summary ˙Content-Length: 108 ˙ ˙Messages-Waiting: no ˙Message-Account: sip:asterisk@1.1.1.1;transport=WS ˙Voice-Message: 0/0 (0/0) ˙ ˙--- [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Trying to put 'NOTIFY sips' onto WS socket destined for 2.2.2.2:61080 [Feb 4 00:40:12] DEBUG[3148] devicestate.c: No provider found, checking channel drivers for SIP - 1061 [Feb 4 00:40:12] DEBUG[3148] chan_sip.c: Checking device state for peer 1061 [Feb 4 00:40:12] DEBUG[3148] devicestate.c: Changing state for SIP/1061 - state 1 (Not in use) [Feb 4 00:40:12] DEBUG[3148] devicestate.c: device 'SIP/1061' state '1' [Feb 4 00:40:12] DEBUG[3150] app_queue.c: Extension '1061@default' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 4 00:40:12] DEBUG[3184] app_queue.c: Device 'SIP/1061' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: Scheduling destruction of SIP dialog 'b35bee67-3af1-a56a-05d0-54e9c96533d0' in 32000 ms (Method: REGISTER) [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61080 ---> ˙SIP/2.0 481 Dialog/Transaction Does Not Exist ˙Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK0db41688 ˙From: "asterisk";tag=as79a688b9 ˙To: ˙Call-ID: 7c64798f60f4f86c7df617af24f0ef0c@1.1.1.1:5060 ˙CSeq: 102 NOTIFY ˙Content-Length: 0 ˙ ˙<-------------> [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 0 [ 45]: SIP/2.0 481 Dialog/Transaction Does Not Exist [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 1 [ 70]: Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK0db41688 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 2 [ 61]: From: "asterisk";tag=as79a688b9 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 3 [ 69]: To: [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 4 [ 62]: Call-ID: 7c64798f60f4f86c7df617af24f0ef0c@1.1.1.1:5060 [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 5 [ 16]: CSeq: 102 NOTIFY [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Feb 4 00:40:12] VERBOSE[4035] chan_sip.c: --- (7 headers 0 lines) --- [Feb 4 00:40:12] DEBUG[4035] chan_sip.c: = Looking for Call ID: 7c64798f60f4f86c7df617af24f0ef0c@1.1.1.1:5060 (Checking To) --From tag as79a688b9 --To-tag [Feb 4 00:40:13] DEBUG[3172] chan_sip.c: Destroying SIP dialog 7c64798f60f4f86c7df617af24f0ef0c@1.1.1.1:5060 [Feb 4 00:40:13] VERBOSE[3172] chan_sip.c: Really destroying SIP dialog '7c64798f60f4f86c7df617af24f0ef0c@1.1.1.1:5060' Method: NOTIFY [Feb 4 00:40:14] DEBUG[4036] http.c: HTTP Request URI is /ws [Feb 4 00:40:14] DEBUG[4036] http.c: match request [ws] with handler [httpstatus] len 0 [Feb 4 00:40:14] DEBUG[4036] http.c: match request [ws] with handler [phoneprov] len 10 [Feb 4 00:40:14] DEBUG[4036] http.c: match request [ws] with handler [static] len 9 [Feb 4 00:40:14] DEBUG[4036] http.c: match request [ws] with handler [ws] len 6 [Feb 4 00:40:14] VERBOSE[4036] res_http_websocket.c: == WebSocket connection from '2.2.2.2:61081' for protocol 'sip' accepted using version '13' [Feb 4 00:40:14] VERBOSE[4036] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61081 ---> ˙REGISTER sip:1.1.1.1 SIP/2.0 ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKUP0dphPQgmsJDebkVKSxkD87nHlUS9No;rport ˙From: "1060";tag=MEN6BcBT0C55PTvEOoxf ˙To: "1060" ˙Contact: "1060";expires=200;click2call=no;+g.oma.sip-im;+audio;language="en,fr" ˙Call-ID: 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 ˙CSeq: 32628 REGISTER ˙Content-Length: 0 ˙Route: ˙Max-Forwards: 70 ˙User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 ˙Organization: Doubango Telecom ˙Supported: path ˙ ˙<-------------> [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 0 [ 36]: REGISTER sip:1.1.1.1 SIP/2.0 [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKUP0dphPQgmsJDebkVKSxkD87nHlUS9No;rport [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 2 [ 63]: From: "1060";tag=MEN6BcBT0C55PTvEOoxf [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 3 [ 36]: To: "1060" [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 4 [144]: Contact: "1060";expires=200;click2call=no;+g.oma.sip-im;+audio;language="en,fr" [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 5 [ 45]: Call-ID: 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 6 [ 20]: CSeq: 32628 REGISTER [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 8 [ 66]: Route: [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 10 [ 49]: User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 11 [ 30]: Organization: Doubango Telecom [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Header 12 [ 15]: Supported: path [Feb 4 00:40:14] VERBOSE[4036] chan_sip.c: --- (13 headers 0 lines) --- [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: = Looking for Call ID: 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 (Checking From) --From tag MEN6BcBT0C55PTvEOoxf --To-tag [Feb 4 00:40:14] DEBUG[4036] acl.c: For destination '2.2.2.2', our source address is '1.1.1.1'. [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Setting SIP_TRANSPORT_WS with address 1.1.1.1:5060 [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Allocating new SIP dialog for 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 - REGISTER (No RTP) [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Initializing initreq for method REGISTER - callid 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 [Feb 4 00:40:14] DEBUG[4036] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:14] DEBUG[4036] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:14] VERBOSE[4036] chan_sip.c: ˙<--- Transmitting (NAT) to 2.2.2.2:61081 ---> ˙SIP/2.0 401 Unauthorized ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKUP0dphPQgmsJDebkVKSxkD87nHlUS9No;received=2.2.2.2;rport=61081 ˙From: "1060";tag=MEN6BcBT0C55PTvEOoxf ˙To: "1060";tag=as4fc9dd09 ˙Call-ID: 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 ˙CSeq: 32628 REGISTER ˙Server: Asterisk PBX 11.7.0 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙WWW-Authenticate: Digest algorithm=MD5, realm="1.1.1.1", nonce="118370ec" ˙Content-Length: 0 ˙ ˙ ˙<------------> [Feb 4 00:40:14] DEBUG[4036] chan_sip.c: Trying to put 'SIP/2.0 401' onto WS socket destined for 2.2.2.2:61081 [Feb 4 00:40:14] VERBOSE[4036] chan_sip.c: Scheduling destruction of SIP dialog '5b67e46e-e2e0-8edc-2009-b8a907f6d6a2' in 32000 ms (Method: REGISTER) [Feb 4 00:40:15] VERBOSE[4036] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61081 ---> ˙REGISTER sip:1.1.1.1 SIP/2.0 ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKyv8i2UGycNakO2c18gZqHN5Xrf0OdGfZ;rport ˙From: "1060";tag=MEN6BcBT0C55PTvEOoxf ˙To: "1060" ˙Contact: "1060";expires=200;click2call=no;+g.oma.sip-im;+audio;language="en,fr" ˙Call-ID: 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 ˙CSeq: 32629 REGISTER ˙Content-Length: 0 ˙Route: ˙Max-Forwards: 70 ˙Authorization: Digest username="1060",realm="1.1.1.1",nonce="118370ec",uri="sip:1.1.1.1",response="6b4322b4da56b6fadb39b514f2a28892",algorithm=MD5 ˙User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 ˙Organization: Doubango Telecom ˙Supported: path ˙ ˙<-------------> [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 0 [ 36]: REGISTER sip:1.1.1.1 SIP/2.0 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKyv8i2UGycNakO2c18gZqHN5Xrf0OdGfZ;rport [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 2 [ 63]: From: "1060";tag=MEN6BcBT0C55PTvEOoxf [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 3 [ 36]: To: "1060" [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 4 [144]: Contact: "1060";expires=200;click2call=no;+g.oma.sip-im;+audio;language="en,fr" [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 5 [ 45]: Call-ID: 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 6 [ 20]: CSeq: 32629 REGISTER [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 8 [ 66]: Route: [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 10 [162]: Authorization: Digest username="1060",realm="1.1.1.1",nonce="118370ec",uri="sip:1.1.1.1",response="6b4322b4da56b6fadb39b514f2a28892",algorithm=MD5 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 11 [ 49]: User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 12 [ 30]: Organization: Doubango Telecom [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 13 [ 15]: Supported: path [Feb 4 00:40:15] VERBOSE[4036] chan_sip.c: --- (14 headers 0 lines) --- [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: = Looking for Call ID: 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 (Checking From) --From tag MEN6BcBT0C55PTvEOoxf --To-tag [Feb 4 00:40:15] DEBUG[4036] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:15] DEBUG[4036] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:15] DEBUG[4036] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:15] DEBUG[4036] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Initializing initreq for method REGISTER - callid 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 [Feb 4 00:40:15] DEBUG[4036] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:15] DEBUG[4036] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: peer '1060' has contacted us over WS even though we prefer UDP. [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Store REGISTER's src-IP:port for call routing. [Feb 4 00:40:15] VERBOSE[4036] chan_sip.c: -- Registered SIP '1060' at 2.2.2.2:61081 [Feb 4 00:40:15] VERBOSE[4036] chan_sip.c: ˙<--- Transmitting (NAT) to 2.2.2.2:61081 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKyv8i2UGycNakO2c18gZqHN5Xrf0OdGfZ;received=2.2.2.2;rport=61081 ˙From: "1060";tag=MEN6BcBT0C55PTvEOoxf ˙To: "1060";tag=as4fc9dd09 ˙Call-ID: 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 ˙CSeq: 32629 REGISTER ˙Server: Asterisk PBX 11.7.0 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Expires: 200 ˙Contact: ;expires=200 ˙Date: Tue, 04 Feb 2014 05:40:15 GMT ˙Content-Length: 0 ˙ ˙ ˙<------------> [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Trying to put 'SIP/2.0 200' onto WS socket destined for 2.2.2.2:61081 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Allocating new SIP dialog for 26c6f32d2b27ae5041628df40eef5bb9@[2001:4802:7801:103:3624:f793:ff20:14]:5060 - NOTIFY (No RTP) [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Feb 4 00:40:15] DEBUG[4036] acl.c: For destination '2.2.2.2', our source address is '1.1.1.1'. [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Setting SIP_TRANSPORT_WS with address 1.1.1.1:5060 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: SIP call-id changed from '26c6f32d2b27ae5041628df40eef5bb9@[2001:4802:7801:103:3624:f793:ff20:14]:5060' to '4d264215017a58e0634165067d7550ad@1.1.1.1:5060' [Feb 4 00:40:15] VERBOSE[4036] chan_sip.c: Scheduling destruction of SIP dialog '4d264215017a58e0634165067d7550ad@1.1.1.1:5060' in 32000 ms (Method: NOTIFY) [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Initializing initreq for method NOTIFY - callid 4d264215017a58e0634165067d7550ad@1.1.1.1:5060 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 0 [ 78]: NOTIFY sips:1060@df7jal23ls0d.invalid;rtcweb-breaker=yes;transport=wss SIP/2.0 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/WS 1.1.1.1:5060;branch=z9hG4bK1c4f6031;rport [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 3 [ 62]: From: "asterisk" ;tag=as488d0bf8 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 4 [ 69]: To: [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 5 [ 57]: Contact: [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 6 [ 62]: Call-ID: 4d264215017a58e0634165067d7550ad@1.1.1.1:5060 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 7 [ 16]: CSeq: 102 NOTIFY [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 8 [ 31]: User-Agent: Asterisk PBX 11.7.0 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 9 [ 22]: Event: message-summary [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 10 [ 48]: Content-Type: application/simple-message-summary [Feb 4 00:40:15] VERBOSE[4036] chan_sip.c: Reliably Transmitting (NAT) to 2.2.2.2:61081: ˙NOTIFY sips:1060@df7jal23ls0d.invalid;rtcweb-breaker=yes;transport=wss SIP/2.0 ˙Via: SIP/2.0/WS 1.1.1.1:5060;branch=z9hG4bK1c4f6031;rport ˙Max-Forwards: 70 ˙From: "asterisk" ;tag=as488d0bf8 ˙To: ˙Contact: ˙Call-ID: 4d264215017a58e0634165067d7550ad@1.1.1.1:5060 ˙CSeq: 102 NOTIFY ˙User-Agent: Asterisk PBX 11.7.0 ˙Event: message-summary ˙Content-Type: application/simple-message-summary ˙Content-Length: 108 ˙ ˙Messages-Waiting: no ˙Message-Account: sip:asterisk@1.1.1.1;transport=WS ˙Voice-Message: 0/0 (0/0) ˙ ˙--- [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Trying to put 'NOTIFY sips' onto WS socket destined for 2.2.2.2:61081 [Feb 4 00:40:15] DEBUG[3148] devicestate.c: No provider found, checking channel drivers for SIP - 1060 [Feb 4 00:40:15] DEBUG[3148] chan_sip.c: Checking device state for peer 1060 [Feb 4 00:40:15] DEBUG[3148] devicestate.c: Changing state for SIP/1060 - state 1 (Not in use) [Feb 4 00:40:15] DEBUG[3148] devicestate.c: device 'SIP/1060' state '1' [Feb 4 00:40:15] DEBUG[3150] app_queue.c: Extension '1060@default' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 4 00:40:15] DEBUG[3184] app_queue.c: Device 'SIP/1060' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 4 00:40:15] VERBOSE[4036] chan_sip.c: Scheduling destruction of SIP dialog '5b67e46e-e2e0-8edc-2009-b8a907f6d6a2' in 32000 ms (Method: REGISTER) [Feb 4 00:40:15] DEBUG[3172] chan_sip.c: Auto destroying SIP dialog '4663ea70-c328-1a11-106a-01b57c088fe0' [Feb 4 00:40:15] DEBUG[3172] chan_sip.c: Destroying SIP dialog 4663ea70-c328-1a11-106a-01b57c088fe0 [Feb 4 00:40:15] VERBOSE[3172] chan_sip.c: Really destroying SIP dialog '4663ea70-c328-1a11-106a-01b57c088fe0' Method: REGISTER [Feb 4 00:40:15] VERBOSE[4036] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61081 ---> ˙SIP/2.0 481 Dialog/Transaction Does Not Exist ˙Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK1c4f6031 ˙From: "asterisk";tag=as488d0bf8 ˙To: ˙Call-ID: 4d264215017a58e0634165067d7550ad@1.1.1.1:5060 ˙CSeq: 102 NOTIFY ˙Content-Length: 0 ˙ ˙<-------------> [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 0 [ 45]: SIP/2.0 481 Dialog/Transaction Does Not Exist [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 1 [ 70]: Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK1c4f6031 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 2 [ 61]: From: "asterisk";tag=as488d0bf8 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 3 [ 69]: To: [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 4 [ 62]: Call-ID: 4d264215017a58e0634165067d7550ad@1.1.1.1:5060 [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 5 [ 16]: CSeq: 102 NOTIFY [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Feb 4 00:40:15] VERBOSE[4036] chan_sip.c: --- (7 headers 0 lines) --- [Feb 4 00:40:15] DEBUG[4036] chan_sip.c: = Looking for Call ID: 4d264215017a58e0634165067d7550ad@1.1.1.1:5060 (Checking To) --From tag as488d0bf8 --To-tag [Feb 4 00:40:15] DEBUG[3172] chan_sip.c: Auto destroying SIP dialog 'ef962185-1ff0-6c25-c5ef-bf0204a4468a' [Feb 4 00:40:15] DEBUG[3172] chan_sip.c: Destroying SIP dialog ef962185-1ff0-6c25-c5ef-bf0204a4468a [Feb 4 00:40:15] VERBOSE[3172] chan_sip.c: Really destroying SIP dialog 'ef962185-1ff0-6c25-c5ef-bf0204a4468a' Method: REGISTER [Feb 4 00:40:15] DEBUG[3172] chan_sip.c: Destroying SIP dialog 4d264215017a58e0634165067d7550ad@1.1.1.1:5060 [Feb 4 00:40:15] VERBOSE[3172] chan_sip.c: Really destroying SIP dialog '4d264215017a58e0634165067d7550ad@1.1.1.1:5060' Method: NOTIFY [Feb 4 00:40:24] VERBOSE[4036] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61081 ---> ˙INVITE sip:1061@1.1.1.1 SIP/2.0 ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKcoaccPVapM5EU9VQREpXC7N4H1cPaA6a;rport ˙From: "1060";tag=Uue9TTmuAqJgE5R4cRGw ˙To: ˙Contact: "1060";impi=1060;ha1=7f73f6e3b99397dda7d2bee39d586a32;+g.oma.sip-im;+sip.ice;language="en,fr" ˙Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b ˙CSeq: 10491 INVITE ˙Content-Type: application/sdp ˙Content-Length: 824 ˙Route: ˙Max-Forwards: 70 ˙User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 ˙Organization: Doubango Telecom ˙ ˙v=0 ˙o=Mozilla-SIPUA-26.0 23985 1 IN IP4 0.0.0.0 ˙s=Doubango Telecom - firefox ˙t=0 0 ˙a=ice-ufrag:5ddef02f ˙a=ice-pwd:66541c7356e3209c3b32be45f6ee9ed9 ˙a=fingerprint:sha-256 65:62:52:9C:99:39:4A:0A:11:4E:A9:F9:35:3B:38:C0:18:11:69:09:14:3D:A8:B7:8A:77:DD:1C:38:4D:EA:22 ˙m=audio 50562 UDP/TLS/RTP/SAVPF 109 0 8 101 ˙c=IN IP4 2.2.2.2 ˙a=rtpmap:109 opus/48000/2 ˙a=ptime:20 ˙a=rtpmap:0 PCMU/8000 ˙a=rtpmap:8 PCMA/8000 ˙a=rtpmap:101 telephone-event/8000 ˙a=fmtp:101 0-15 ˙a=sendrecv ˙a=setup:actpass ˙a=candidate:0 1 UDP 2128609535 192.168.1.138 50562 typ host ˙a=candidate:1 1 UDP 1692467199 2.2.2.2 50562 typ srflx raddr 192.168.1.138 rport 50562 ˙a=candidate:0 2 UDP 2128609534 192.168.1.138 50563 typ host ˙a=candidate:1 2 UDP 1692467198 2.2.2.2 50563 typ srflx raddr 192.168.1.138 rport 50563 ˙a=rtcp-mux ˙<-------------> [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 0 [ 39]: INVITE sip:1061@1.1.1.1 SIP/2.0 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKcoaccPVapM5EU9VQREpXC7N4H1cPaA6a;rport [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 2 [ 63]: From: "1060";tag=Uue9TTmuAqJgE5R4cRGw [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 3 [ 30]: To: [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 4 [181]: Contact: "1060";impi=1060;ha1=7f73f6e3b99397dda7d2bee39d586a32;+g.oma.sip-im;+sip.ice;language="en,fr" [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 5 [ 45]: Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 6 [ 18]: CSeq: 10491 INVITE [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 7 [ 29]: Content-Type: application/sdp [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 8 [ 19]: Content-Length: 824 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 9 [ 66]: Route: [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 10 [ 16]: Max-Forwards: 70 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 11 [ 49]: User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 12 [ 30]: Organization: Doubango Telecom [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 13 [ 0]: [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 0 [ 3]: v=0 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 1 [ 43]: o=Mozilla-SIPUA-26.0 23985 1 IN IP4 0.0.0.0 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 2 [ 28]: s=Doubango Telecom - firefox [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 3 [ 5]: t=0 0 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 4 [ 20]: a=ice-ufrag:5ddef02f [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 5 [ 42]: a=ice-pwd:66541c7356e3209c3b32be45f6ee9ed9 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 6 [117]: a=fingerprint:sha-256 65:62:52:9C:99:39:4A:0A:11:4E:A9:F9:35:3B:38:C0:18:11:69:09:14:3D:A8:B7:8A:77:DD:1C:38:4D:EA:22 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 7 [ 43]: m=audio 50562 UDP/TLS/RTP/SAVPF 109 0 8 101 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 8 [ 21]: c=IN IP4 2.2.2.2 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 9 [ 25]: a=rtpmap:109 opus/48000/2 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 10 [ 10]: a=ptime:20 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 11 [ 20]: a=rtpmap:0 PCMU/8000 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 12 [ 20]: a=rtpmap:8 PCMA/8000 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 13 [ 33]: a=rtpmap:101 telephone-event/8000 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 14 [ 15]: a=fmtp:101 0-15 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 15 [ 10]: a=sendrecv [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 16 [ 15]: a=setup:actpass [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 17 [ 59]: a=candidate:0 1 UDP 2128609535 192.168.1.138 50562 typ host [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 18 [ 91]: a=candidate:1 1 UDP 1692467199 2.2.2.2 50562 typ srflx raddr 192.168.1.138 rport 50562 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 19 [ 59]: a=candidate:0 2 UDP 2128609534 192.168.1.138 50563 typ host [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 20 [ 91]: a=candidate:1 2 UDP 1692467198 2.2.2.2 50563 typ srflx raddr 192.168.1.138 rport 50563 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 21 [ 10]: a=rtcp-mux [Feb 4 00:40:24] VERBOSE[4036] chan_sip.c: --- (13 headers 22 lines) --- [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: = Looking for Call ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b (Checking From) --From tag Uue9TTmuAqJgE5R4cRGw --To-tag [Feb 4 00:40:24] DEBUG[4036] acl.c: For destination '2.2.2.2', our source address is '1.1.1.1'. [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Setting SIP_TRANSPORT_WS with address 1.1.1.1:5060 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Allocating new SIP dialog for 525c1a90-24ae-75ce-cd1b-ef3246c22b8b - INVITE (No RTP) [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Initializing initreq for method INVITE - callid 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Using INVITE request as basis request - 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Found peer '1060' for '1060' from 2.2.2.2:61081 [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: ˙<--- Reliably Transmitting (NAT) to 2.2.2.2:61081 ---> ˙SIP/2.0 401 Unauthorized ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKcoaccPVapM5EU9VQREpXC7N4H1cPaA6a;received=2.2.2.2;rport=61081 ˙From: "1060";tag=Uue9TTmuAqJgE5R4cRGw ˙To: ;tag=as79910a09 ˙Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b ˙CSeq: 10491 INVITE ˙Server: Asterisk PBX 11.7.0 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙WWW-Authenticate: Digest algorithm=MD5, realm="1.1.1.1", nonce="71c6e246" ˙Content-Length: 0 ˙ ˙ ˙<------------> [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 401' onto WS socket destined for 2.2.2.2:61081 [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Scheduling destruction of SIP dialog '525c1a90-24ae-75ce-cd1b-ef3246c22b8b' in 32000 ms (Method: INVITE) [Feb 4 00:40:24] VERBOSE[4036] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61081 ---> ˙ACK sip:1061@1.1.1.1 SIP/2.0 ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKcoaccPVapM5EU9VQREpXC7N4H1cPaA6a;rport ˙From: "1060";tag=Uue9TTmuAqJgE5R4cRGw ˙To: ;tag=as79910a09 ˙Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b ˙CSeq: 10491 ACK ˙Content-Length: 0 ˙Route: ˙Max-Forwards: 70 ˙ ˙<-------------> [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 0 [ 36]: ACK sip:1061@1.1.1.1 SIP/2.0 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKcoaccPVapM5EU9VQREpXC7N4H1cPaA6a;rport [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 2 [ 63]: From: "1060";tag=Uue9TTmuAqJgE5R4cRGw [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 3 [ 45]: To: ;tag=as79910a09 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 4 [ 45]: Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 5 [ 15]: CSeq: 10491 ACK [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 7 [ 66]: Route: [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 8 [ 16]: Max-Forwards: 70 [Feb 4 00:40:24] VERBOSE[4036] chan_sip.c: --- (9 headers 0 lines) --- [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: = Looking for Call ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b (Checking From) --From tag Uue9TTmuAqJgE5R4cRGw --To-tag as79910a09 [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Stopping retransmission on '525c1a90-24ae-75ce-cd1b-ef3246c22b8b' of Response 10491: Match Not Found [Feb 4 00:40:24] VERBOSE[4036] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61081 ---> ˙INVITE sip:1061@1.1.1.1 SIP/2.0 ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKT7bSbrFqKkfe4Xrqw2TVn21ld1omp4s5;rport ˙From: "1060";tag=Uue9TTmuAqJgE5R4cRGw ˙To: ˙Contact: "1060";impi=1060;ha1=7f73f6e3b99397dda7d2bee39d586a32;+g.oma.sip-im;+sip.ice;language="en,fr" ˙Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b ˙CSeq: 10492 INVITE ˙Content-Type: application/sdp ˙Content-Length: 824 ˙Route: ˙Max-Forwards: 70 ˙Authorization: Digest username="1060",realm="1.1.1.1",nonce="71c6e246",uri="sip:1061@1.1.1.1",response="793921a93ca8fb5952264139215efa28",algorithm=MD5 ˙User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 ˙Organization: Doubango Telecom ˙ ˙v=0 ˙o=Mozilla-SIPUA-26.0 23985 1 IN IP4 0.0.0.0 ˙s=Doubango Telecom - firefox ˙t=0 0 ˙a=ice-ufrag:5ddef02f ˙a=ice-pwd:66541c7356e3209c3b32be45f6ee9ed9 ˙a=fingerprint:sha-256 65:62:52:9C:99:39:4A:0A:11:4E:A9:F9:35:3B:38:C0:18:11:69:09:14:3D:A8:B7:8A:77:DD:1C:38:4D:EA:22 ˙m=audio 50562 UDP/TLS/RTP/SAVPF 109 0 8 101 ˙c=IN IP4 2.2.2.2 ˙a=rtpmap:109 opus/48000/2 ˙a=ptime:20 ˙a=rtpmap:0 PCMU/8000 ˙a=rtpmap:8 PCMA/8000 ˙a=rtpmap:101 telephone-event/8000 ˙a=fmtp:101 0-15 ˙a=sendrecv ˙a=setup:actpass ˙a=candidate:0 1 UDP 2128609535 192.168.1.138 50562 typ host ˙a=candidate:1 1 UDP 1692467199 2.2.2.2 50562 typ srflx raddr 192.168.1.138 rport 50562 ˙a=candidate:0 2 UDP 2128609534 192.168.1.138 50563 typ host ˙a=candidate:1 2 UDP 1692467198 2.2.2.2 50563 typ srflx raddr 192.168.1.138 rport 50563 ˙a=rtcp-mux ˙<-------------> [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 0 [ 39]: INVITE sip:1061@1.1.1.1 SIP/2.0 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKT7bSbrFqKkfe4Xrqw2TVn21ld1omp4s5;rport [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 2 [ 63]: From: "1060";tag=Uue9TTmuAqJgE5R4cRGw [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 3 [ 30]: To: [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 4 [181]: Contact: "1060";impi=1060;ha1=7f73f6e3b99397dda7d2bee39d586a32;+g.oma.sip-im;+sip.ice;language="en,fr" [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 5 [ 45]: Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 6 [ 18]: CSeq: 10492 INVITE [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 7 [ 29]: Content-Type: application/sdp [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 8 [ 19]: Content-Length: 824 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 9 [ 66]: Route: [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 10 [ 16]: Max-Forwards: 70 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 11 [167]: Authorization: Digest username="1060",realm="1.1.1.1",nonce="71c6e246",uri="sip:1061@1.1.1.1",response="793921a93ca8fb5952264139215efa28",algorithm=MD5 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 12 [ 49]: User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 13 [ 30]: Organization: Doubango Telecom [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Header 14 [ 0]: [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 0 [ 3]: v=0 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 1 [ 43]: o=Mozilla-SIPUA-26.0 23985 1 IN IP4 0.0.0.0 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 2 [ 28]: s=Doubango Telecom - firefox [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 3 [ 5]: t=0 0 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 4 [ 20]: a=ice-ufrag:5ddef02f [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 5 [ 42]: a=ice-pwd:66541c7356e3209c3b32be45f6ee9ed9 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 6 [117]: a=fingerprint:sha-256 65:62:52:9C:99:39:4A:0A:11:4E:A9:F9:35:3B:38:C0:18:11:69:09:14:3D:A8:B7:8A:77:DD:1C:38:4D:EA:22 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 7 [ 43]: m=audio 50562 UDP/TLS/RTP/SAVPF 109 0 8 101 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 8 [ 21]: c=IN IP4 2.2.2.2 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 9 [ 25]: a=rtpmap:109 opus/48000/2 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 10 [ 10]: a=ptime:20 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 11 [ 20]: a=rtpmap:0 PCMU/8000 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 12 [ 20]: a=rtpmap:8 PCMA/8000 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 13 [ 33]: a=rtpmap:101 telephone-event/8000 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 14 [ 15]: a=fmtp:101 0-15 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 15 [ 10]: a=sendrecv [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 16 [ 15]: a=setup:actpass [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 17 [ 59]: a=candidate:0 1 UDP 2128609535 192.168.1.138 50562 typ host [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 18 [ 91]: a=candidate:1 1 UDP 1692467199 2.2.2.2 50562 typ srflx raddr 192.168.1.138 rport 50562 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 19 [ 59]: a=candidate:0 2 UDP 2128609534 192.168.1.138 50563 typ host [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 20 [ 91]: a=candidate:1 2 UDP 1692467198 2.2.2.2 50563 typ srflx raddr 192.168.1.138 rport 50563 [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: Body 21 [ 10]: a=rtcp-mux [Feb 4 00:40:24] VERBOSE[4036] chan_sip.c: --- (14 headers 22 lines) --- [Feb 4 00:40:24] DEBUG[4036] chan_sip.c: = Looking for Call ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b (Checking From) --From tag Uue9TTmuAqJgE5R4cRGw --To-tag [Feb 4 00:40:24] DEBUG[4036] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4036] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] DEBUG[4036] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4036] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Initializing initreq for method INVITE - callid 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Using INVITE request as basis request - 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Found peer '1060' for '1060' from 2.2.2.2:61081 [Feb 4 00:40:24] DEBUG[4036][C-00000000] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f400003d708' [Feb 4 00:40:24] DEBUG[4036][C-00000000] res_rtp_asterisk.c: Allocated port 13456 for RTP instance '0x7f400003d708' [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '10.176.162.151' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '10.176.162.151' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '192.168.168.4' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '192.168.168.4' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] rtp_engine.c: RTP instance '0x7f400003d708' is setup and ready to go [Feb 4 00:40:24] DEBUG[4036][C-00000000] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f400003d708' [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '10.176.162.151' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '10.176.162.151' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '192.168.168.4' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '192.168.168.4' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] VERBOSE[4036][C-00000000] netsock2.c: == Using SIP RTP CoS mark 5 [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Setting NAT on RTP to Off [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing session-level SDP o=Mozilla-SIPUA-26.0 23985 1 IN IP4 0.0.0.0... OK. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing session-level SDP s=Doubango Telecom - firefox... UNSUPPORTED OR FAILED. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing session-level SDP a=ice-ufrag:5ddef02f... OK. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing session-level SDP a=ice-pwd:66541c7356e3209c3b32be45f6ee9ed9... OK. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing session-level SDP a=fingerprint:sha-256 65:62:52:9C:99:39:4A:0A:11:4E:A9:F9:35:3B:38:C0:18:11:69:09:14:3D:A8:B7:8A:77:DD:1C:38:4D:EA:22... OK. [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Found RTP audio format 109 [Feb 4 00:40:24] DEBUG[4036][C-00000000] rtp_engine.c: Setting payload 109 based on m type on 0x7f3fe165e780 [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Found RTP audio format 0 [Feb 4 00:40:24] DEBUG[4036][C-00000000] rtp_engine.c: Setting payload 0 based on m type on 0x7f3fe165e780 [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Found RTP audio format 8 [Feb 4 00:40:24] DEBUG[4036][C-00000000] rtp_engine.c: Setting payload 8 based on m type on 0x7f3fe165e780 [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Found RTP audio format 101 [Feb 4 00:40:24] DEBUG[4036][C-00000000] rtp_engine.c: Setting payload 101 based on m type on 0x7f3fe165e780 [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '2.2.2.2' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '2.2.2.2' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP c=IN IP4 2.2.2.2... OK. [Feb 4 00:40:24] DEBUG[4036][C-00000000] rtp_engine.c: Unsetting payload 109 on 0x7f3fe165e780 [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Found unknown media description format opus for ID 109 [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:109 opus/48000/2... UNSUPPORTED OR FAILED. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Found audio description format PCMU for ID 0 [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Found audio description format PCMA for ID 8 [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Found audio description format telephone-event for ID 101 [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=setup:actpass... OK. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '192.168.1.138' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '192.168.1.138' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=candidate:0 1 UDP 2128609535 192.168.1.138 50562 typ host... OK. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '2.2.2.2' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '2.2.2.2' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '192.168.1.138' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '192.168.1.138' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=candidate:1 1 UDP 1692467199 2.2.2.2 50562 typ srflx raddr 192.168.1.138 rport 50562... OK. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '192.168.1.138' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '192.168.1.138' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=candidate:0 2 UDP 2128609534 192.168.1.138 50563 typ host... OK. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '2.2.2.2' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '2.2.2.2' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '192.168.1.138' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '192.168.1.138' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=candidate:1 2 UDP 1692467198 2.2.2.2 50563 typ srflx raddr 192.168.1.138 rport 50563... OK. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Processing media-level (audio) SDP a=rtcp-mux... UNSUPPORTED OR FAILED. [Feb 4 00:40:24] WARNING[4036][C-00000000] chan_sip.c: Processed DTLS [TRUE] [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Capabilities: us - (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|speex16|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14|testlaw|g719|speex32|slin12|slin24|slin32|slin44|slin48|slin96|slin192|silk8|silk12|silk16|silk24), peer - audio=(ulaw|alaw)/video=(nothing)/text=(nothing), combined - (ulaw|alaw) [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Feb 4 00:40:24] DEBUG[4036][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f400003d708' [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Peer audio RTP is at port 2.2.2.2:50562 [Feb 4 00:40:24] DEBUG[4036][C-00000000] rtp_engine.c: Copying payload 0 from 0x7f3fe165e780 to 0x7f400003d8d0 [Feb 4 00:40:24] DEBUG[4036][C-00000000] rtp_engine.c: Copying payload 8 from 0x7f3fe165e780 to 0x7f400003d8d0 [Feb 4 00:40:24] DEBUG[4036][C-00000000] rtp_engine.c: Copying payload 101 from 0x7f3fe165e780 to 0x7f400003d8d0 [Feb 4 00:40:24] DEBUG[4036][C-00000000] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f400003d708' [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: We're settling with these formats: (ulaw|alaw) [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Checking SIP call limits for device 1060 [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Updating call counter for incoming call [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4036][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: Looking for 1061 in default (domain 1.1.1.1) [Feb 4 00:40:24] DEBUG[4036][C-00000000] format_pref.c: Could not find preferred codec - Going for the best codec [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: *** Our native formats are (ulaw) [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: *** Joint capabilities are (ulaw|alaw) [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: *** Our capabilities are (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|speex16|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14|testlaw|g719|speex32|slin12|slin24|slin32|slin44|slin48|slin96|slin192|silk8|silk12|silk16|silk24) [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: This channel will not be able to handle video. [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: build_route: Contact hop: "1060";impi=1060;ha1=7f73f6e3b99397dda7d2bee39d586a32;+g.oma.sip-im;+sip.ice;language="en,fr" [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: list_route: hop: [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: SIP/1060-00000000: New call is still down.... Trying... [Feb 4 00:40:24] VERBOSE[4036][C-00000000] chan_sip.c: ˙<--- Transmitting (NAT) to 2.2.2.2:61081 ---> ˙SIP/2.0 100 Trying ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKT7bSbrFqKkfe4Xrqw2TVn21ld1omp4s5;received=2.2.2.2;rport=61081 ˙From: "1060";tag=Uue9TTmuAqJgE5R4cRGw ˙To: ˙Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b ˙CSeq: 10492 INVITE ˙Server: Asterisk PBX 11.7.0 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Contact: ˙Content-Length: 0 ˙ ˙ ˙<------------> [Feb 4 00:40:24] DEBUG[4036][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 100' onto WS socket destined for 2.2.2.2:61081 [Feb 4 00:40:24] DEBUG[3148] devicestate.c: No provider found, checking channel drivers for SIP - 1060 [Feb 4 00:40:24] DEBUG[3148] chan_sip.c: Checking device state for peer 1060 [Feb 4 00:40:24] DEBUG[3148] devicestate.c: Changing state for SIP/1060 - state 1 (Not in use) [Feb 4 00:40:24] DEBUG[3148] devicestate.c: device 'SIP/1060' state '1' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Result of 'HINT' is 'SIP/1061' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Launching 'Gosub' [Feb 4 00:40:24] VERBOSE[4037][C-00000000] pbx.c: -- Executing [1061@default:1] Gosub("SIP/1060-00000000", "1061,stdexten(SIP/1061)") in new stack [Feb 4 00:40:24] DEBUG[4037][C-00000000] app_stack.c: Channel SIP/1060-00000000 has no datastore, so we're allocating one. [Feb 4 00:40:24] DEBUG[4037][C-00000000] app_stack.c: Setting 'ARG1' to 'SIP/1061' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Launching 'NoOp' [Feb 4 00:40:24] VERBOSE[4037][C-00000000] pbx.c: -- Executing [1061@default:50000] NoOp("SIP/1060-00000000", "Start stdexten") in new stack [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Result of 'EXTEN' is '1061' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Launching 'Set' [Feb 4 00:40:24] VERBOSE[4037][C-00000000] pbx.c: -- Executing [1061@default:50001] Set("SIP/1060-00000000", "LOCAL(ext)=1061") in new stack [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Result of 'ARG1' is 'SIP/1061' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Launching 'Set' [Feb 4 00:40:24] VERBOSE[4037][C-00000000] pbx.c: -- Executing [1061@default:50002] Set("SIP/1060-00000000", "LOCAL(dev)=SIP/1061") in new stack [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Result of 'ARG2' is NULL [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Launching 'Set' [Feb 4 00:40:24] VERBOSE[4037][C-00000000] pbx.c: -- Executing [1061@default:50003] Set("SIP/1060-00000000", "LOCAL(cntx)=") in new stack [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Result of 'ext' is '1061' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Result of 'cntx' is '' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Function result is '1' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Expression result is '0' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Result of 'cntx' is '' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Function result is '' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Launching 'Set' [Feb 4 00:40:24] VERBOSE[4037][C-00000000] pbx.c: -- Executing [1061@default:50004] Set("SIP/1060-00000000", "LOCAL(mbx)=1061") in new stack [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Result of 'dev' is 'SIP/1061' [Feb 4 00:40:24] DEBUG[4037][C-00000000] pbx.c: Launching 'Dial' [Feb 4 00:40:24] VERBOSE[4037][C-00000000] pbx.c: -- Executing [1061@default:50005] Dial("SIP/1060-00000000", "SIP/1061,20") in new stack [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Asked to create a SIP channel with formats: (ulaw) [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Allocating new SIP dialog for 060662850b6682390eb46e7a3e8a75fd@[2001:4802:7801:103:3624:f793:ff20:14]:5060 - INVITE (No RTP) [Feb 4 00:40:24] DEBUG[4037][C-00000000] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f400c06c298' [Feb 4 00:40:24] DEBUG[4037][C-00000000] res_rtp_asterisk.c: Allocated port 16156 for RTP instance '0x7f400c06c298' [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: Splitting '10.176.162.151' into... [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: ...host '10.176.162.151' and port ''. [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: Splitting '192.168.168.4' into... [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: ...host '192.168.168.4' and port ''. [Feb 4 00:40:24] DEBUG[3140] res_odbc.c: odbc_release_obj2(0x7f4004057c98) called (obj->txf = (nil)) [Feb 4 00:40:24] DEBUG[3184] app_queue.c: Device 'SIP/1060' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] DEBUG[4037][C-00000000] rtp_engine.c: RTP instance '0x7f400c06c298' is setup and ready to go [Feb 4 00:40:24] DEBUG[4037][C-00000000] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f400c06c298' [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: Splitting '10.176.162.151' into... [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: ...host '10.176.162.151' and port ''. [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: Splitting '192.168.168.4' into... [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: ...host '192.168.168.4' and port ''. [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: Splitting '1.1.1.1' into... [Feb 4 00:40:24] DEBUG[4037][C-00000000] netsock2.c: ...host '1.1.1.1' and port ''. [Feb 4 00:40:24] VERBOSE[4037][C-00000000] netsock2.c: == Using SIP RTP CoS mark 5 [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Setting NAT on RTP to On [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Feb 4 00:40:24] DEBUG[4037][C-00000000] acl.c: For destination '2.2.2.2', our source address is '1.1.1.1'. [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Setting SIP_TRANSPORT_WS with address 1.1.1.1:5060 [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Setting NAT on RTP to On [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: SIP call-id changed from '060662850b6682390eb46e7a3e8a75fd@[2001:4802:7801:103:3624:f793:ff20:14]:5060' to '477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060' [Feb 4 00:40:24] DEBUG[4037][C-00000000] format_pref.c: Could not find preferred codec - Going for the best codec [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: *** Our native formats are (ulaw) [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: *** Joint capabilities are (ulaw) [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: *** Our capabilities are (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|speex16|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14|testlaw|g719|speex32|slin12|slin24|slin32|slin44|slin48|slin96|slin192|silk8|silk12|silk16|silk24) [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: *** Our preferred formats from the incoming channel are (ulaw) [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: This channel will not be able to handle video. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel_internal_api.c: Channel Call ID changing from [C-00000000] to [C-00000000] [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable DIALEDTIME. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable ANSWEREDTIME. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable DIALEDPEERNAME. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable DIALEDPEERNUMBER. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable DIALSTATUS. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable mbx. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable cntx. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable dev. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable ext. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable ARGC. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable ARG1. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable SIPCALLID. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable SIPDOMAIN. [Feb 4 00:40:24] DEBUG[4037][C-00000000] channel.c: Not copying variable SIPURI. [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Outgoing Call for 1061 [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Updating call counter for outgoing call [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: This call needs video offers, but there's no video support enabled! [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: We think we can do text [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: This call needs text offers, but there's no text support enabled ! [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: ** Our capability: (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|speex16|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14|testlaw|g719|speex32|slin12|slin24|slin32|slin44|slin48|slin96|slin192|silk8|silk12|silk16|silk24) Video flag: False Text flag: False [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: ** Our prefcodec: (ulaw) [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Audio is at 16156 [Feb 4 00:40:24] DEBUG[4037][C-00000000] sip/sdp_crypto.c: local_key64 2DAgllzPg+tO6GRItXomgCl7I7IEGzs30sMW8MuS len 40 [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100003 (ulaw) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100001 (g723) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100002 (gsm) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100002 (gsm) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100004 (alaw) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100004 (alaw) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100005 (g726aal2) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100006 (adpcm) to SDP [Feb 4 00:40:24] DEBUG[3140] res_odbc.c: odbc_release_obj2(0x7f4004057c98) called (obj->txf = (nil)) [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100007 (lpc10) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100008 (g729) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100009 (speex) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100010 (ilbc) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100011 (g726) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100012 (g722) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100013 (siren7) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100014 (siren14) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100015 (g719) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100016 (speex16) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100017 (testlaw) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100017 (testlaw) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100018 (silk8) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100018 (silk12) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100018 (silk16) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100018 (silk24) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100019 (slin) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100020 (slin12) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100021 (slin16) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100022 (slin24) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100023 (slin32) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100024 (slin44) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100025 (slin48) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100026 (slin96) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100027 (slin192) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100028 (speex32) to SDP [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: -- Done with adding codecs to SDP [Feb 4 00:40:24] DEBUG[4037][C-00000000] res_rtp_asterisk.c: SRTP_DTLS--Inside ast_rtp_dtls_get_fingerprint [Feb 4 00:40:24] DEBUG[4037][C-00000000] res_rtp_asterisk.c: SRTP_DTLS--Inside ast_rtp_dtls_get_fingerprint [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Done building SDP. Settling with this capability: (g723|gsm|ulaw|alaw|g726|adpcm|slin|lpc10|g729|speex|speex16|ilbc|g726aal2|g722|slin16|jpeg|png|h261|h263|h263p|h264|mpeg4|red|t140|siren7|siren14|testlaw|g719|speex32|slin12|slin24|slin32|slin44|slin48|slin96|slin192|silk8|silk12|silk16|silk24) [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Initializing initreq for method INVITE - callid 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 0 [ 78]: INVITE sips:1061@df7jal23ls0d.invalid;rtcweb-breaker=yes;transport=wss SIP/2.0 [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/WS 1.1.1.1:5060;branch=z9hG4bK212b468c;rport [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 3 [ 58]: From: "New User" ;tag=as5c54e108 [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 4 [ 69]: To: [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 5 [ 53]: Contact: [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 6 [ 62]: Call-ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 8 [ 31]: User-Agent: Asterisk PBX 11.7.0 [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 9 [ 35]: Date: Tue, 04 Feb 2014 05:40:24 GMT [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Feb 4 00:40:24] VERBOSE[4037][C-00000000] chan_sip.c: Reliably Transmitting (NAT) to 2.2.2.2:61080: ˙INVITE sips:1061@df7jal23ls0d.invalid;rtcweb-breaker=yes;transport=wss SIP/2.0 ˙Via: SIP/2.0/WS 1.1.1.1:5060;branch=z9hG4bK212b468c;rport ˙Max-Forwards: 70 ˙From: "New User" ;tag=as5c54e108 ˙To: ˙Contact: ˙Call-ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 ˙CSeq: 102 INVITE ˙User-Agent: Asterisk PBX 11.7.0 ˙Date: Tue, 04 Feb 2014 05:40:24 GMT ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Content-Type: application/sdp ˙Content-Length: 2077 ˙ ˙v=0 ˙o=root 691573191 691573191 IN IP4 1.1.1.1 ˙s=Asterisk PBX 11.7.0 ˙c=IN IP4 1.1.1.1 ˙t=0 0 ˙m=audio 16156 RTP/SAVPF 0 4 3 3 8 8 112 5 7 18 110 97 111 9 102 115 116 117 96 100 107 108 10 118 119 101 ˙a=rtpmap:0 PCMU/8000 ˙a=rtpmap:4 G723/8000 ˙a=fmtp:4 annexa=no ˙a=rtpmap:3 GSM/8000 ˙a=rtpmap:3 GSM/8000 ˙a=rtpmap:8 PCMA/8000 ˙a=rtpmap:8 PCMA/8000 ˙a=rtpmap:112 AAL2-G726-32/8000 ˙a=rtpmap:5 DVI4/8000 ˙a=rtpmap:7 LPC/8000 ˙a=rtpmap:18 G729/8000 ˙a=fmtp:18 annexb=no ˙a=rtpmap:110 speex/8000 ˙a=rtpmap:97 iLBC/8000 ˙a=fmtp:97 mode=30 ˙a=rtpmap:111 G726-32/8000 ˙a=rtpmap:9 G722/8000 ˙a=rtpmap:102 G7221/16000 ˙a=fmtp:102 bitrate=32000 ˙a=rtpmap:115 G7221/32000 ˙a=fmtp:115 bitrate=48000 ˙a=rtpmap:116 G719/48000 ˙a=fmtp:116 bitrate=64000 ˙a=rtpmap:117 speex/16000 ˙a=rtpmap:96 SILK/8000 ˙a=fmtp:96 maxaveragebitrate=10000 ˙a=fmtp:96 usedtx=0 ˙a=fmtp:96 useinbandfec=1 ˙a=rtpmap:100 SILK/12000 ˙a=fmtp:100 maxaveragebitrate=12000 ˙a=fmtp:100 usedtx=0 ˙a=fmtp:100 useinbandfec=1 ˙a=rtpmap:107 SILK/16000 ˙a=fmtp:107 maxaveragebitrate=20000 ˙a=fmtp:107 usedtx=0 ˙a=fmtp:107 useinbandfec=1 ˙a=rtpmap:108 SILK/24000 ˙a=fmtp:108 maxaveragebitrate=30000 ˙a=fmtp:108 usedtx=0 ˙a=fmtp:108 useinbandfec=1 ˙a=rtpmap:10 L16/8000 ˙a=rtpmap:118 L16/16000 ˙a=rtpmap:119 speex/32000 ˙a=rtpmap:101 telephone-event/8000 ˙a=fmtp:101 0-16 ˙a=silenceSupp:off - - - - ˙a=ptime:20 ˙a=ice-ufrag:31b1f27c2426a56a68fdc51b516682f6 ˙a=ice-pwd:4c33d4467e084b9c1682dce1040c5d80 ˙a=candidate:Ha2f2df83 1 UDP 2130706431 1.1.1.1 16156 typ host ˙a=candidate:Hab0a297 1 UDP 2130706431 10.176.162.151 16156 typ host ˙a=candidate:Hc0a8a804 1 UDP 2130706431 192.168.168.4 16156 typ host ˙a=candidate:Sa2f2df83 1 UDP 1694498815 1.1.1.1 16156 typ srflx ˙a=candidate:Ha2f2df83 2 UDP 2130706430 1.1.1.1 16157 typ host ˙a=candidate:Hab0a297 2 UDP 2130706430 10.176.162.151 16157 typ host ˙a=candidate:Hc0a8a804 2 UDP 2130706430 192.168.168.4 16157 typ host ˙a=candidate:Sa2f2df83 2 UDP 1694498814 1.1.1.1 16157 typ srflx ˙a=connection:new ˙a=setup:active ˙a=sendrecv ˙ ˙--- [Feb 4 00:40:24] DEBUG[4037][C-00000000] chan_sip.c: Trying to put 'INVITE sips' onto WS socket destined for 2.2.2.2:61080 [Feb 4 00:40:24] VERBOSE[4037][C-00000000] app_dial.c: -- Called SIP/1061 [Feb 4 00:40:24] VERBOSE[4035] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61080 ---> ˙SIP/2.0 100 Trying (sent from the Transaction Layer) ˙Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK212b468c ˙From: "New User";tag=as5c54e108 ˙To: ˙Call-ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 ˙CSeq: 102 INVITE ˙Content-Length: 0 ˙ ˙<-------------> [Feb 4 00:40:24] DEBUG[4035] chan_sip.c: Header 0 [ 52]: SIP/2.0 100 Trying (sent from the Transaction Layer) [Feb 4 00:40:24] DEBUG[4035] chan_sip.c: Header 1 [ 70]: Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK212b468c [Feb 4 00:40:24] DEBUG[4035] chan_sip.c: Header 2 [ 57]: From: "New User";tag=as5c54e108 [Feb 4 00:40:24] DEBUG[4035] chan_sip.c: Header 3 [ 69]: To: [Feb 4 00:40:24] DEBUG[4035] chan_sip.c: Header 4 [ 62]: Call-ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 [Feb 4 00:40:24] DEBUG[4035] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Feb 4 00:40:24] DEBUG[4035] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Feb 4 00:40:24] VERBOSE[4035] chan_sip.c: --- (7 headers 0 lines) --- [Feb 4 00:40:24] DEBUG[4035] chan_sip.c: = Looking for Call ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 (Checking To) --From tag as5c54e108 --To-tag [Feb 4 00:40:24] DEBUG[4035][C-00000000] chan_sip.c: SIP response 100 to standard invite [Feb 4 00:40:25] VERBOSE[4035] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61080 ---> ˙SIP/2.0 180 Ringing ˙Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK212b468c ˙From: "New User";tag=as5c54e108 ˙To: ;tag=IFka9J7xPJePpKxqCIi3 ˙Contact: ˙Call-ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 ˙CSeq: 102 INVITE ˙Content-Length: 0 ˙Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE ˙ ˙<-------------> [Feb 4 00:40:25] DEBUG[4035] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Feb 4 00:40:25] DEBUG[4035] chan_sip.c: Header 1 [ 70]: Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK212b468c [Feb 4 00:40:25] DEBUG[4035] chan_sip.c: Header 2 [ 57]: From: "New User";tag=as5c54e108 [Feb 4 00:40:25] DEBUG[4035] chan_sip.c: Header 3 [ 94]: To: ;tag=IFka9J7xPJePpKxqCIi3 [Feb 4 00:40:25] DEBUG[4035] chan_sip.c: Header 4 [ 55]: Contact: [Feb 4 00:40:25] DEBUG[4035] chan_sip.c: Header 5 [ 62]: Call-ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 [Feb 4 00:40:25] DEBUG[4035] chan_sip.c: Header 6 [ 16]: CSeq: 102 INVITE [Feb 4 00:40:25] DEBUG[4035] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Feb 4 00:40:25] DEBUG[4035] chan_sip.c: Header 8 [ 79]: Allow: ACK, BYE, CANCEL, INVITE, MESSAGE, NOTIFY, OPTIONS, PRACK, REFER, UPDATE [Feb 4 00:40:25] VERBOSE[4035] chan_sip.c: --- (9 headers 0 lines) --- [Feb 4 00:40:25] DEBUG[4035] chan_sip.c: = Looking for Call ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 (Checking To) --From tag as5c54e108 --To-tag IFka9J7xPJePpKxqCIi3 [Feb 4 00:40:25] DEBUG[4035][C-00000000] chan_sip.c: SIP response 180 to standard invite [Feb 4 00:40:25] DEBUG[4035][C-00000000] chan_sip.c: build_route: Contact hop: [Feb 4 00:40:25] VERBOSE[4035][C-00000000] chan_sip.c: list_route: hop: [Feb 4 00:40:25] DEBUG[3148] devicestate.c: No provider found, checking channel drivers for SIP - 1061 [Feb 4 00:40:25] DEBUG[3148] chan_sip.c: Checking device state for peer 1061 [Feb 4 00:40:25] DEBUG[3148] devicestate.c: Changing state for SIP/1061 - state 1 (Not in use) [Feb 4 00:40:25] DEBUG[3148] devicestate.c: device 'SIP/1061' state '1' [Feb 4 00:40:25] DEBUG[3184] app_queue.c: Device 'SIP/1061' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 4 00:40:25] VERBOSE[4037][C-00000000] app_dial.c: -- SIP/1061-00000001 is ringing [Feb 4 00:40:25] DEBUG[4037][C-00000000] rtp_engine.c: Setting early bridge SDP of 'SIP/1060-00000000' with that of 'SIP/1061-00000001' [Feb 4 00:40:25] VERBOSE[4037][C-00000000] chan_sip.c: ˙<--- Transmitting (NAT) to 2.2.2.2:61081 ---> ˙SIP/2.0 180 Ringing ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKT7bSbrFqKkfe4Xrqw2TVn21ld1omp4s5;received=2.2.2.2;rport=61081 ˙From: "1060";tag=Uue9TTmuAqJgE5R4cRGw ˙To: ;tag=as251c019b ˙Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b ˙CSeq: 10492 INVITE ˙Server: Asterisk PBX 11.7.0 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Contact: ˙Content-Length: 0 ˙ ˙ ˙<------------> [Feb 4 00:40:25] DEBUG[4037][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 180' onto WS socket destined for 2.2.2.2:61081 [Feb 4 00:40:32] VERBOSE[4035] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61080 ---> ˙SIP/2.0 603 Failed to get local SDP ˙Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK212b468c ˙From: "New User";tag=as5c54e108 ˙To: ;tag=IFka9J7xPJePpKxqCIi3 ˙Call-ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 ˙CSeq: 102 INVITE ˙Content-Length: 0 ˙Reason: SIP; cause=603; text="Failed to get local SDP" ˙ ˙<-------------> [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 0 [ 35]: SIP/2.0 603 Failed to get local SDP [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 1 [ 70]: Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK212b468c [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 2 [ 57]: From: "New User";tag=as5c54e108 [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 3 [ 94]: To: ;tag=IFka9J7xPJePpKxqCIi3 [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 4 [ 62]: Call-ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 7 [ 54]: Reason: SIP; cause=603; text="Failed to get local SDP" [Feb 4 00:40:32] VERBOSE[4035] chan_sip.c: --- (8 headers 0 lines) --- [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: = Looking for Call ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 (Checking To) --From tag as5c54e108 --To-tag IFka9J7xPJePpKxqCIi3 [Feb 4 00:40:32] VERBOSE[4035][C-00000000] chan_sip.c: -- Got SIP response 603 "Failed to get local SDP" back from 2.2.2.2:61080 [Feb 4 00:40:32] DEBUG[4035][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f400c06c298' [Feb 4 00:40:32] DEBUG[4035][C-00000000] chan_sip.c: Strict routing enforced for session 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 [Feb 4 00:40:32] VERBOSE[4035][C-00000000] chan_sip.c: set_destination: Parsing for address/port to send to [Feb 4 00:40:32] VERBOSE[4035][C-00000000] chan_sip.c: set_destination: URI is for WebSocket, we can't set destination [Feb 4 00:40:32] VERBOSE[4035][C-00000000] chan_sip.c: Transmitting (NAT) to 2.2.2.2:61080: ˙ACK sips:1061@df7jal23ls0d.invalid;transport=wss SIP/2.0 ˙Via: SIP/2.0/WS 1.1.1.1:5060;branch=z9hG4bK212b468c;rport ˙Max-Forwards: 70 ˙From: "New User" ;tag=as5c54e108 ˙To: ;tag=IFka9J7xPJePpKxqCIi3 ˙Contact: ˙Call-ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 ˙CSeq: 102 ACK ˙User-Agent: Asterisk PBX 11.7.0 ˙Content-Length: 0 ˙ ˙ ˙--- [Feb 4 00:40:32] DEBUG[4035][C-00000000] chan_sip.c: Trying to put 'ACK sips:10' onto WS socket destined for 2.2.2.2:61080 [Feb 4 00:40:32] DEBUG[4035][C-00000000] chan_sip.c: Setting SIP_ALREADYGONE on dialog 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 [Feb 4 00:40:32] VERBOSE[4037][C-00000000] app_dial.c: -- SIP/1061-00000001 is busy [Feb 4 00:40:32] DEBUG[4037][C-00000000] channel.c: Hanging up channel 'SIP/1061-00000001' [Feb 4 00:40:32] DEBUG[4037][C-00000000] chan_sip.c: Hangup call SIP/1061-00000001, SIP callid 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 [Feb 4 00:40:32] DEBUG[4037][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f400c06c298' [Feb 4 00:40:32] VERBOSE[4037][C-00000000] app_dial.c: == Everyone is busy/congested at this time (1:1/0/0) [Feb 4 00:40:32] DEBUG[4037][C-00000000] app_dial.c: Exiting with DIALSTATUS=BUSY. [Feb 4 00:40:32] DEBUG[3148] devicestate.c: No provider found, checking channel drivers for SIP - 1061 [Feb 4 00:40:32] DEBUG[3148] chan_sip.c: Checking device state for peer 1061 [Feb 4 00:40:32] DEBUG[3148] devicestate.c: Changing state for SIP/1061 - state 1 (Not in use) [Feb 4 00:40:32] DEBUG[3148] devicestate.c: device 'SIP/1061' state '1' [Feb 4 00:40:32] DEBUG[4037][C-00000000] pbx.c: Result of 'DIALSTATUS' is 'BUSY' [Feb 4 00:40:32] DEBUG[4037][C-00000000] pbx.c: Launching 'Goto' [Feb 4 00:40:32] VERBOSE[4037][C-00000000] pbx.c: -- Executing [1061@default:50006] Goto("SIP/1060-00000000", "stdexten-BUSY,1") in new stack [Feb 4 00:40:32] VERBOSE[4037][C-00000000] pbx.c: -- Goto (default,stdexten-BUSY,1) [Feb 4 00:40:32] DEBUG[4037][C-00000000] pbx.c: Result of 'mbx' is '1061' [Feb 4 00:40:32] DEBUG[4037][C-00000000] pbx.c: Launching 'VoiceMail' [Feb 4 00:40:32] VERBOSE[4037][C-00000000] pbx.c: -- Executing [stdexten-BUSY@default:1] VoiceMail("SIP/1060-00000000", "1061,b") in new stack [Feb 4 00:40:32] DEBUG[4037][C-00000000] chan_sip.c: SIP answering channel: SIP/1060-00000000 [Feb 4 00:40:32] DEBUG[4037][C-00000000] res_rtp_asterisk.c: Setting the marker bit due to a source update [Feb 4 00:40:32] DEBUG[4037][C-00000000] chan_sip.c: Setting framing from config on incoming call [Feb 4 00:40:32] DEBUG[4037][C-00000000] chan_sip.c: ** Our capability: (ulaw|alaw) Video flag: True Text flag: True [Feb 4 00:40:32] DEBUG[4037][C-00000000] chan_sip.c: ** Our prefcodec: (nothing) [Feb 4 00:40:32] VERBOSE[4037][C-00000000] chan_sip.c: Audio is at 13456 [Feb 4 00:40:32] DEBUG[4037][C-00000000] sip/sdp_crypto.c: local_key64 PPs/3tMcdrUrWtgYOcuSrv6XwaTVscd4OIrNg3TU len 40 [Feb 4 00:40:32] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100003 (ulaw) to SDP [Feb 4 00:40:32] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100003 (ulaw) to SDP [Feb 4 00:40:32] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100004 (alaw) to SDP [Feb 4 00:40:32] VERBOSE[4037][C-00000000] chan_sip.c: Adding codec 100004 (alaw) to SDP [Feb 4 00:40:32] VERBOSE[4037][C-00000000] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Feb 4 00:40:32] DEBUG[4037][C-00000000] chan_sip.c: -- Done with adding codecs to SDP [Feb 4 00:40:32] DEBUG[4037][C-00000000] res_rtp_asterisk.c: SRTP_DTLS--Inside ast_rtp_dtls_get_fingerprint [Feb 4 00:40:32] DEBUG[4037][C-00000000] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw) [Feb 4 00:40:32] VERBOSE[4037][C-00000000] chan_sip.c: ˙<--- Reliably Transmitting (NAT) to 2.2.2.2:61081 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKT7bSbrFqKkfe4Xrqw2TVn21ld1omp4s5;received=2.2.2.2;rport=61081 ˙From: "1060";tag=Uue9TTmuAqJgE5R4cRGw ˙To: ;tag=as251c019b ˙Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b ˙CSeq: 10492 INVITE ˙Server: Asterisk PBX 11.7.0 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Contact: ˙Content-Type: application/sdp ˙Content-Length: 1147 ˙ ˙v=0 ˙o=root 1019395642 1019395642 IN IP4 1.1.1.1 ˙s=Asterisk PBX 11.7.0 ˙c=IN IP4 1.1.1.1 ˙t=0 0 ˙m=audio 13456 RTP/SAVPF 0 0 8 8 101 ˙a=rtpmap:0 PCMU/8000 ˙a=rtpmap:0 PCMU/8000 ˙a=rtpmap:8 PCMA/8000 ˙a=rtpmap:8 PCMA/8000 ˙a=rtpmap:101 telephone-event/8000 ˙a=fmtp:101 0-16 ˙a=silenceSupp:off - - - - ˙a=ptime:20 ˙a=ice-ufrag:65995da458bcce2700606f7f32e6f063 ˙a=ice-pwd:3f72bcc92d32ca251e7ac4bc4d634066 ˙a=candidate:Ha2f2df83 1 UDP 2130706431 1.1.1.1 13456 typ host ˙a=candidate:Hab0a297 1 UDP 2130706431 10.176.162.151 13456 typ host ˙a=candidate:Hc0a8a804 1 UDP 2130706431 192.168.168.4 13456 typ host ˙a=candidate:Sa2f2df83 1 UDP 1694498815 1.1.1.1 13456 typ srflx ˙a=candidate:Ha2f2df83 2 UDP 2130706430 1.1.1.1 13457 typ host ˙a=candidate:Hab0a297 2 UDP 2130706430 10.176.162.151 13457 typ host ˙a=candidate:Hc0a8a804 2 UDP 2130706430 192.168.168.4 13457 typ host ˙a=candidate:Sa2f2df83 2 UDP 1694498814 1.1.1.1 13457 typ srflx ˙a=connection:new ˙a=setup:active ˙a=fingerprint:SHA-256 4B:D0:F1:39:36:B7:B0:91:57:87:9F:1F:6E:CF:C4:37:D2:BB:C7:72:F9:DC:A4:CB:50:64:9E:0D:FF:D0:40:39 ˙a=sendrecv ˙ ˙<------------> [Feb 4 00:40:32] DEBUG[4037][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 200' onto WS socket destined for 2.2.2.2:61081 [Feb 4 00:40:32] DEBUG[3148] devicestate.c: No provider found, checking channel drivers for SIP - 1060 [Feb 4 00:40:32] DEBUG[3148] chan_sip.c: Checking device state for peer 1060 [Feb 4 00:40:32] DEBUG[3148] devicestate.c: Changing state for SIP/1060 - state 1 (Not in use) [Feb 4 00:40:32] DEBUG[3148] devicestate.c: device 'SIP/1060' state '1' [Feb 4 00:40:32] DEBUG[3140] res_odbc.c: odbc_release_obj2(0x7f4004057c98) called (obj->txf = (nil)) [Feb 4 00:40:32] DEBUG[3140] res_odbc.c: odbc_release_obj2(0x7f4004057c98) called (obj->txf = (nil)) [Feb 4 00:40:32] DEBUG[3184] app_queue.c: Device 'SIP/1061' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 4 00:40:32] DEBUG[3140] res_odbc.c: odbc_release_obj2(0x7f4004057c98) called (obj->txf = (nil)) [Feb 4 00:40:32] DEBUG[3184] app_queue.c: Device 'SIP/1060' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 4 00:40:32] VERBOSE[4036] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61081 ---> ˙ACK sip:1061@1.1.1.1:5060;transport=WS SIP/2.0 ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKUPBwPNG5EJ5zz3INIU9H;rport ˙From: "1060";tag=Uue9TTmuAqJgE5R4cRGw ˙To: ;tag=as251c019b ˙Contact: "1060";+g.oma.sip-im;+sip.ice;language="en,fr" ˙Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b ˙CSeq: 10492 ACK ˙Content-Length: 0 ˙Route: ˙Max-Forwards: 70 ˙Authorization: Digest username="1060",realm="1.1.1.1",nonce="71c6e246",uri="sip:1061@1.1.1.1:5060;transport=WS",response="5a53e28cb1f5f97baa3e348b3bd90d63",algorithm=MD5 ˙User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 ˙Organization: Doubango Telecom ˙ ˙<-------------> [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 0 [ 54]: ACK sip:1061@1.1.1.1:5060;transport=WS SIP/2.0 [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 1 [ 78]: Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bKUPBwPNG5EJ5zz3INIU9H;rport [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 2 [ 63]: From: "1060";tag=Uue9TTmuAqJgE5R4cRGw [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 3 [ 45]: To: ;tag=as251c019b [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 4 [134]: Contact: "1060";+g.oma.sip-im;+sip.ice;language="en,fr" [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 5 [ 45]: Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 6 [ 15]: CSeq: 10492 ACK [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 8 [ 66]: Route: [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 10 [185]: Authorization: Digest username="1060",realm="1.1.1.1",nonce="71c6e246",uri="sip:1061@1.1.1.1:5060;transport=WS",response="5a53e28cb1f5f97baa3e348b3bd90d63",algorithm=MD5 [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 11 [ 49]: User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: Header 12 [ 30]: Organization: Doubango Telecom [Feb 4 00:40:32] VERBOSE[4036] chan_sip.c: --- (13 headers 0 lines) --- [Feb 4 00:40:32] DEBUG[4036] chan_sip.c: = Looking for Call ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b (Checking From) --From tag Uue9TTmuAqJgE5R4cRGw --To-tag as251c019b [Feb 4 00:40:32] DEBUG[4036][C-00000000] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Feb 4 00:40:32] DEBUG[4036][C-00000000] chan_sip.c: Stopping retransmission on '525c1a90-24ae-75ce-cd1b-ef3246c22b8b' of Response 10492: Match Not Found [Feb 4 00:40:32] VERBOSE[4035] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61080 ---> ˙SIP/2.0 481 Dialog/Transaction Does Not Exist ˙Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK212b468c ˙From: "New User";tag=as5c54e108 ˙To: ;tag=IFka9J7xPJePpKxqCIi3 ˙Call-ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 ˙CSeq: 102 ACK ˙Content-Length: 0 ˙ ˙<-------------> [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 0 [ 45]: SIP/2.0 481 Dialog/Transaction Does Not Exist [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 1 [ 70]: Via: SIP/2.0/WS 1.1.1.1:5060;rport=5060;branch=z9hG4bK212b468c [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 2 [ 57]: From: "New User";tag=as5c54e108 [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 3 [ 94]: To: ;tag=IFka9J7xPJePpKxqCIi3 [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 4 [ 62]: Call-ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 5 [ 13]: CSeq: 102 ACK [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Feb 4 00:40:32] VERBOSE[4035] chan_sip.c: --- (7 headers 0 lines) --- [Feb 4 00:40:32] DEBUG[4035] chan_sip.c: = Looking for Call ID: 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 (Checking To) --From tag as5c54e108 --To-tag IFka9J7xPJePpKxqCIi3 [Feb 4 00:40:32] WARNING[4035][C-00000000] chan_sip.c: Remote host can't match request ACK to call '477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060'. Giving up. [Feb 4 00:40:32] VERBOSE[3157] res_rtp_asterisk.c: -- ICE is now complete [Feb 4 00:40:32] DEBUG[3172] chan_sip.c: Destroying SIP dialog 477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060 [Feb 4 00:40:32] VERBOSE[3172] chan_sip.c: Really destroying SIP dialog '477df3784220ff3e1e96db5a4958aab4@1.1.1.1:5060' Method: INVITE [Feb 4 00:40:32] DEBUG[3172] rtp_engine.c: Destroyed RTP instance '0x7f400c06c298' [Feb 4 00:40:33] DEBUG[4037][C-00000000] channel.c: Didn't receive a media frame from SIP/1060-00000000 within 500 ms of answering. Continuing anyway [Feb 4 00:40:33] DEBUG[4037][C-00000000] app_voicemail.c: Before find_user [Feb 4 00:40:33] DEBUG[4037][C-00000000] res_config_odbc.c: Skip: 0; SQL: SELECT * FROM asterisk_db_voicemail WHERE mailbox = ? AND context = ? [Feb 4 00:40:33] DEBUG[4037][C-00000000] res_config_odbc.c: Parameter 1 ('mailbox') = '1061' [Feb 4 00:40:33] DEBUG[4037][C-00000000] res_config_odbc.c: Parameter 2 ('context') = 'default' [Feb 4 00:40:33] DEBUG[4037][C-00000000] res_odbc.c: odbc_release_obj2(0x7f4004057c98) called (obj->txf = (nil)) [Feb 4 00:40:33] WARNING[4037][C-00000000] app_voicemail.c: No entry in voicemail config file for '1061' [Feb 4 00:40:33] DEBUG[4037][C-00000000] pbx.c: Launching 'Return' [Feb 4 00:40:33] VERBOSE[4037][C-00000000] pbx.c: -- Executing [stdexten-BUSY@default:2] Return("SIP/1060-00000000", "") in new stack [Feb 4 00:40:33] VERBOSE[4037][C-00000000] pbx.c: -- Auto fallthrough, channel 'SIP/1060-00000000' status is 'BUSY' [Feb 4 00:40:33] DEBUG[4037][C-00000000] channel.c: Driver for channel 'SIP/1060-00000000' does not support indication 5, emulating it [Feb 4 00:40:33] DEBUG[4037][C-00000000] channel.c: Set channel SIP/1060-00000000 to write format slin [Feb 4 00:40:33] DEBUG[4037][C-00000000] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Feb 4 00:40:33] DEBUG[4037][C-00000000] res_rtp_asterisk.c: Ooh, format changed from unknown to ulaw [Feb 4 00:40:33] DEBUG[4037][C-00000000] res_rtp_asterisk.c: Created smoother: format: ulaw ms: 20 len: 160 [Feb 4 00:40:33] DEBUG[4037][C-00000000] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x7f400003d708' [Feb 4 00:40:38] DEBUG[4037][C-00000000] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0x7f400003d708' [Feb 4 00:40:41] VERBOSE[4036] chan_sip.c: ˙<--- SIP read from WS:2.2.2.2:61081 ---> ˙BYE sip:1061@1.1.1.1:5060;transport=WS SIP/2.0 ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bK0ISLtkCTxuFiFLtDT6AZez8aNTrScJvq;rport ˙From: "1060";tag=Uue9TTmuAqJgE5R4cRGw ˙To: ;tag=as251c019b ˙Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b ˙CSeq: 10493 BYE ˙Content-Length: 0 ˙Route: ˙Max-Forwards: 70 ˙Accept-Contact: *;+g.oma.sip-im ˙Accept-Contact: *;+sip.ice ˙Accept-Contact: *;language="en,fr" ˙Authorization: Digest username="1060",realm="1.1.1.1",nonce="71c6e246",uri="sip:1061@1.1.1.1:5060;transport=WS",response="9dff907352a20c8d73ca652d68409a7d",algorithm=MD5 ˙User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 ˙Organization: Doubango Telecom ˙ ˙<-------------> [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 0 [ 54]: BYE sip:1061@1.1.1.1:5060;transport=WS SIP/2.0 [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bK0ISLtkCTxuFiFLtDT6AZez8aNTrScJvq;rport [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 2 [ 63]: From: "1060";tag=Uue9TTmuAqJgE5R4cRGw [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 3 [ 45]: To: ;tag=as251c019b [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 4 [ 45]: Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 5 [ 15]: CSeq: 10493 BYE [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 7 [ 66]: Route: [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 8 [ 16]: Max-Forwards: 70 [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 9 [ 31]: Accept-Contact: *;+g.oma.sip-im [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 10 [ 26]: Accept-Contact: *;+sip.ice [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 11 [ 34]: Accept-Contact: *;language="en,fr" [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 12 [185]: Authorization: Digest username="1060",realm="1.1.1.1",nonce="71c6e246",uri="sip:1061@1.1.1.1:5060;transport=WS",response="9dff907352a20c8d73ca652d68409a7d",algorithm=MD5 [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 13 [ 49]: User-Agent: IM-client/OMA1.0 sipML5-v1.2014.01.27 [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: Header 14 [ 30]: Organization: Doubango Telecom [Feb 4 00:40:41] VERBOSE[4036] chan_sip.c: --- (15 headers 0 lines) --- [Feb 4 00:40:41] DEBUG[4036] chan_sip.c: = Looking for Call ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b (Checking From) --From tag Uue9TTmuAqJgE5R4cRGw --To-tag as251c019b [Feb 4 00:40:41] DEBUG[4036][C-00000000] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Feb 4 00:40:41] DEBUG[4036][C-00000000] chan_sip.c: Initializing initreq for method BYE - callid 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:41] DEBUG[4036][C-00000000] chan_sip.c: Setting SIP_ALREADYGONE on dialog 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:41] DEBUG[4036][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f400003d708' [Feb 4 00:40:41] VERBOSE[4036][C-00000000] chan_sip.c: Scheduling destruction of SIP dialog '525c1a90-24ae-75ce-cd1b-ef3246c22b8b' in 32000 ms (Method: BYE) [Feb 4 00:40:41] DEBUG[4036][C-00000000] chan_sip.c: Received bye, issuing owner hangup [Feb 4 00:40:41] VERBOSE[4036][C-00000000] chan_sip.c: ˙<--- Transmitting (NAT) to 2.2.2.2:61081 ---> ˙SIP/2.0 200 OK ˙Via: SIP/2.0/WSS df7jal23ls0d.invalid;branch=z9hG4bK0ISLtkCTxuFiFLtDT6AZez8aNTrScJvq;received=2.2.2.2;rport=61081 ˙From: "1060";tag=Uue9TTmuAqJgE5R4cRGw ˙To: ;tag=as251c019b ˙Call-ID: 525c1a90-24ae-75ce-cd1b-ef3246c22b8b ˙CSeq: 10493 BYE ˙Server: Asterisk PBX 11.7.0 ˙Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH ˙Supported: replaces, timer ˙Content-Length: 0 ˙ ˙ ˙<------------> [Feb 4 00:40:41] DEBUG[4036][C-00000000] chan_sip.c: Trying to put 'SIP/2.0 200' onto WS socket destined for 2.2.2.2:61081 [Feb 4 00:40:41] DEBUG[4037][C-00000000] channel.c: Set channel SIP/1060-00000000 to write format ulaw [Feb 4 00:40:41] DEBUG[4037][C-00000000] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Feb 4 00:40:41] DEBUG[4037][C-00000000] channel.c: Soft-Hanging up channel 'SIP/1060-00000000' [Feb 4 00:40:41] DEBUG[4037][C-00000000] channel.c: Hanging up channel 'SIP/1060-00000000' [Feb 4 00:40:41] DEBUG[4037][C-00000000] chan_sip.c: Hangup call SIP/1060-00000000, SIP callid 525c1a90-24ae-75ce-cd1b-ef3246c22b8b [Feb 4 00:40:41] DEBUG[4037][C-00000000] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f400003d708' [Feb 4 00:40:41] DEBUG[3140] res_odbc.c: odbc_release_obj2(0x7f4004057c98) called (obj->txf = (nil)) [Feb 4 00:40:41] DEBUG[4037][C-00000000] res_odbc.c: odbc_release_obj2(0x7f4004057c98) called (obj->txf = (nil)) [Feb 4 00:40:41] DEBUG[3148] devicestate.c: No provider found, checking channel drivers for SIP - 1060 [Feb 4 00:40:41] DEBUG[3148] chan_sip.c: Checking device state for peer 1060 [Feb 4 00:40:41] DEBUG[3148] devicestate.c: Changing state for SIP/1060 - state 1 (Not in use) [Feb 4 00:40:41] DEBUG[3148] devicestate.c: device 'SIP/1060' state '1' [Feb 4 00:40:41] DEBUG[3140] res_odbc.c: odbc_release_obj2(0x7f4004057c98) called (obj->txf = (nil)) [Feb 4 00:40:41] DEBUG[3140] res_odbc.c: odbc_release_obj2(0x7f4004057c98) called (obj->txf = (nil)) [Feb 4 00:40:41] DEBUG[3184] app_queue.c: Device 'SIP/1060' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Feb 4 00:40:44] DEBUG[3172] chan_sip.c: Auto destroying SIP dialog 'b35bee67-3af1-a56a-05d0-54e9c96533d0' [Feb 4 00:40:44] DEBUG[3172] chan_sip.c: Destroying SIP dialog b35bee67-3af1-a56a-05d0-54e9c96533d0 [Feb 4 00:40:44] VERBOSE[3172] chan_sip.c: Really destroying SIP dialog 'b35bee67-3af1-a56a-05d0-54e9c96533d0' Method: REGISTER [Feb 4 00:40:47] DEBUG[3172] chan_sip.c: Auto destroying SIP dialog '5b67e46e-e2e0-8edc-2009-b8a907f6d6a2' [Feb 4 00:40:47] DEBUG[3172] chan_sip.c: Destroying SIP dialog 5b67e46e-e2e0-8edc-2009-b8a907f6d6a2 [Feb 4 00:40:47] VERBOSE[3172] chan_sip.c: Really destroying SIP dialog '5b67e46e-e2e0-8edc-2009-b8a907f6d6a2' Method: REGISTER