[Aug 7 14:28:14.835] DEBUG[18944] chan_sip.c: Auto destroying SIP dialog '5f9ae1f06751467b0c3dca1f169e7396@test.test.com:5060' [Aug 7 14:28:14.835] DEBUG[18944] chan_sip.c: Destroying SIP dialog 5f9ae1f06751467b0c3dca1f169e7396@test.test.com:5060 [Aug 7 14:28:20.469] DEBUG[18944] chan_sip.c: = Looking for Call ID: 3890068728@10.255.255.157 (Checking From) --From tag 4052487425 --To-tag [Aug 7 14:28:20.469] DEBUG[18944] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:28:20.469] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:20.469] DEBUG[18944] netsock2.c: Splitting '10.255.255.157:5063' into... [Aug 7 14:28:20.469] DEBUG[18944] netsock2.c: ...host '10.255.255.157' and port '5063'. [Aug 7 14:28:20.469] DEBUG[18944] chan_sip.c: NAT detected for 10.255.255.157 / 172.21.254.254 [Aug 7 14:28:20.469] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 3890068728@10.255.255.157 - INVITE (No RTP) [Aug 7 14:28:20.469] DEBUG[18944][C-00000001] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 7 14:28:20.469] DEBUG[18944][C-00000001] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces" [Aug 7 14:28:20.469] DEBUG[18944][C-00000001] sip/reqresp_parser.c: Found SIP option: -replaces- [Aug 7 14:28:20.469] DEBUG[18944][C-00000001] sip/reqresp_parser.c: Matched SIP option: replaces [Aug 7 14:28:20.469] DEBUG[18944][C-00000001] netsock2.c: Splitting '10.255.255.157:5063' into... [Aug 7 14:28:20.469] DEBUG[18944][C-00000001] netsock2.c: ...host '10.255.255.157' and port '5063'. [Aug 7 14:28:20.469] DEBUG[18944][C-00000001] chan_sip.c: NAT detected for 10.255.255.157 / 172.21.254.254 [Aug 7 14:28:20.469] DEBUG[18944][C-00000001] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:28:20.469] DEBUG[18944][C-00000001] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:28:20.469] DEBUG[18944][C-00000001] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 172.21.254.254:5063 [Aug 7 14:28:20.490] DEBUG[18944] chan_sip.c: = Looking for Call ID: 3890068728@10.255.255.157 (Checking From) --From tag 4052487425 --To-tag as20ecc2af [Aug 7 14:28:20.490] DEBUG[18944][C-00000001] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 7 14:28:20.490] DEBUG[18944][C-00000001] chan_sip.c: Stopping retransmission on '3890068728@10.255.255.157' of Response 1: Match Found [Aug 7 14:28:20.588] DEBUG[18944] chan_sip.c: = Looking for Call ID: 3890068728@10.255.255.157 (Checking From) --From tag 4052487425 --To-tag [Aug 7 14:28:20.588] DEBUG[18944] netsock2.c: Splitting 'stasis.daktela.com:5060' into... [Aug 7 14:28:20.588] DEBUG[18944] netsock2.c: ...host 'stasis.daktela.com' and port '5060'. [Aug 7 14:28:20.588] DEBUG[18944] netsock2.c: Splitting 'stasis.daktela.com:5060' into... [Aug 7 14:28:20.588] DEBUG[18944] netsock2.c: ...host 'stasis.daktela.com' and port '5060'. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: Splitting '10.255.255.157:5063' into... [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: ...host '10.255.255.157' and port '5063'. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: NAT detected for 10.255.255.157 / 172.21.254.254 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f7fb00017a8' [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] res_rtp_asterisk.c: Allocated port 17610 for RTP instance '0x7f7fb00017a8' [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: RTP instance '0x7f7fb00017a8' is setup and ready to go [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: Splitting 'stasis' into... [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: ...host 'stasis' and port ''. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f7fb00017a8' [Aug 7 14:28:20.588] VERBOSE[18944][C-00000001] netsock2.c: Using SIP RTP CoS mark 5 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Setting NAT on RTP to On [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing session-level SDP o=- 20027 20027 IN IP4 10.255.255.157... OK. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing session-level SDP s=SDP data... UNSUPPORTED OR FAILED. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: Splitting '10.255.255.157' into... [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: ...host '10.255.255.157' and port ''. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing session-level SDP c=IN IP4 10.255.255.157... OK. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f7f8e6cfa20 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f7f8e6cfa20 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7f7f8e6cfa20 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Setting tx payload type 9 based on m type on 0x7f7f8e6cfa20 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Setting framing to 20 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 0 (0x7f7fb0004910) from 0x7f7f8e6cfa20 to 0x7f7f8e6cfa20 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 8 (0x7f7fb0012110) from 0x7f7f8e6cfa20 to 0x7f7f8e6cfa20 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 9 (0x7f7fb0015cb0) from 0x7f7f8e6cfa20 to 0x7f7f8e6cfa20 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 18 (0x7f7fb0006450) from 0x7f7f8e6cfa20 to 0x7f7f8e6cfa20 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 101 (0x7f7fb00070d0) from 0x7f7f8e6cfa20 to 0x7f7f8e6cfa20 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] acl.c: For destination '10.255.255.157', our source address is '95.80.200.221'. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f7fb00017a8' [Aug 7 14:28:20.588] VERBOSE[18944][C-00000001] res_rtp_asterisk.c: 0x7f7fb000c830 -- Strict RTP learning after remote address set to: 10.255.255.157:11790 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Copying rx payload mapping 0 (0x7f7fb0004910) from 0x7f7f8e6cfa20 to 0x7f7fb0001980 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Copying rx payload mapping 8 (0x7f7fb0012110) from 0x7f7f8e6cfa20 to 0x7f7fb0001980 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Copying rx payload mapping 9 (0x7f7fb0015cb0) from 0x7f7f8e6cfa20 to 0x7f7fb0001980 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Copying rx payload mapping 18 (0x7f7fb0006450) from 0x7f7f8e6cfa20 to 0x7f7fb0001980 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Copying rx payload mapping 101 (0x7f7fb00070d0) from 0x7f7f8e6cfa20 to 0x7f7fb0001980 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Copying tx payload mapping 0 (0x7f7fb0004910) from 0x7f7f8e6cfa20 to 0x7f7fb0001980 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Copying tx payload mapping 8 (0x7f7fb0012110) from 0x7f7f8e6cfa20 to 0x7f7fb0001980 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Copying tx payload mapping 9 (0x7f7fb0015cb0) from 0x7f7f8e6cfa20 to 0x7f7fb0001980 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Copying tx payload mapping 18 (0x7f7fb0006450) from 0x7f7f8e6cfa20 to 0x7f7fb0001980 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] rtp_engine.c: Copying tx payload mapping 101 (0x7f7fb00070d0) from 0x7f7f8e6cfa20 to 0x7f7fb0001980 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f7fb00017a8' [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: We're settling with these formats: (alaw) [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Checking SIP call limits for device 322 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: Updating call counter for incoming call [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: Splitting 'stasis.daktela.com:5060' into... [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] channel.c: Channel 0x7f7fb001c988 'SIP/322-00000000' allocated [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: *** Our native formats are (alaw) [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: *** Joint capabilities are (alaw) [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: *** Our capabilities are (alaw) [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Aug 7 14:28:20.588] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 240 [Aug 7 14:28:20.588] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 240 [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: This channel will not be able to handle video. [Aug 7 14:28:20.588] DEBUG[18944][C-00000001] chan_sip.c: SIP/322-00000000: New call is still down.... Trying... [Aug 7 14:28:20.589] DEBUG[18944][C-00000001] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 172.21.254.254:5063 [Aug 7 14:28:20.589] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - 322 [Aug 7 14:28:20.589] DEBUG[18805] chan_sip.c: Checking device state for peer 322 [Aug 7 14:28:20.589] DEBUG[18805] devicestate.c: Changing state for SIP/322 - state 2 (In use) [Aug 7 14:28:20.589] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - 322 [Aug 7 14:28:20.589] DEBUG[18805] chan_sip.c: Checking device state for peer 322 [Aug 7 14:28:20.589] DEBUG[18805] devicestate.c: Changing state for SIP/322 - state 2 (In use) [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 438 [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 438 [Aug 7 14:28:20.589] DEBUG[18794] threadpool.c: Increasing threadpool stasis-core's size by 1 [Aug 7 14:28:20.589] DEBUG[18811] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock322 [Aug 7 14:28:20.589] DEBUG[18811] devicestate.c: Checking provider Custom with Custom [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 495 [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 495 [Aug 7 14:28:20.589] DEBUG[18811] db.c: Unable to find key 'StopCock322' in family 'CustomDevstate' [Aug 7 14:28:20.589] DEBUG[18811] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock322 [Aug 7 14:28:20.589] DEBUG[18811] devicestate.c: Checking provider Custom with Custom [Aug 7 14:28:20.589] DEBUG[18811] db.c: Unable to find key 'StopCock322' in family 'CustomDevstate' [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 496 [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 496 [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 442 [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 442 [Aug 7 14:28:20.589] DEBUG[19660][C-00000001] pbx.c: Launching 'Goto' [Aug 7 14:28:20.589] VERBOSE[19660][C-00000001] pbx.c: Executing [25@internal-device:1] Goto("SIP/322-00000000", "start") in new stack [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:28:20.589] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:28:20.589] VERBOSE[19660][C-00000001] pbx_builtins.c: Goto (internal-device,25,2) [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] pbx_variables.c: Evaluating 'EXTEN' (from 'EXTEN}' len 5) [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] pbx_variables.c: Result of 'EXTEN' is '25' [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] func_strings.c: String to search: (25) [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] func_strings.c: Characters to find: ( ) [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] func_strings.c: Character to replace with: () [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] pbx_variables.c: Function REPLACE(EXTEN," ") result is '25' [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] func_strings.c: FUNCTION REGEX (^[0123456789*]+$)(25) [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] pbx_variables.c: Function REGEX("^[0123456789*]+$" 25) result is '1' [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] pbx_variables.c: Expression result is '1' [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] pbx_variables.c: Evaluating 'EXTEN' (from 'EXTEN}' len 5) [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] pbx_variables.c: Result of 'EXTEN' is '25' [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] func_strings.c: String to search: (25) [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] func_strings.c: Characters to find: ( ) [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] func_strings.c: Character to replace with: () [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] pbx_variables.c: Function REPLACE(EXTEN," ") result is '25' [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] pbx.c: Launching 'ExecIf' [Aug 7 14:28:20.590] VERBOSE[19660][C-00000001] pbx.c: Executing [25@internal-device:2] ExecIf("SIP/322-00000000", "1?Goto(25,detect)") in new stack [Aug 7 14:28:20.590] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:28:20.590] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:28:20.590] VERBOSE[19660][C-00000001] pbx_builtins.c: Goto (internal-device,25,4) [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] pbx.c: Launching 'NoOp' [Aug 7 14:28:20.590] VERBOSE[19660][C-00000001] pbx.c: Executing [25@internal-device:4] NoOp("SIP/322-00000000", "") in new stack [Aug 7 14:28:20.590] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 484 [Aug 7 14:28:20.590] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 484 [Aug 7 14:28:20.590] DEBUG[19660][C-00000001] pbx_variables.c: Result of 'EXTEN' is '25' [Aug 7 14:28:20.591] DEBUG[19660][C-00000001] pbx_variables.c: Function DIALPLAN_EXISTS(internal-device-custom,25,1) result is '1' [Aug 7 14:28:20.591] DEBUG[19660][C-00000001] pbx_variables.c: Expression result is '1' [Aug 7 14:28:20.591] DEBUG[19660][C-00000001] pbx_variables.c: Result of 'EXTEN' is '25' [Aug 7 14:28:20.591] DEBUG[19660][C-00000001] pbx.c: Launching 'GotoIf' [Aug 7 14:28:20.591] VERBOSE[19660][C-00000001] pbx.c: Executing [25@internal-device:5] GotoIf("SIP/322-00000000", "1?internal-device-custom,25,1") in new stack [Aug 7 14:28:20.591] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 515 [Aug 7 14:28:20.591] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 515 [Aug 7 14:28:20.591] VERBOSE[19660][C-00000001] pbx_builtins.c: Goto (internal-device-custom,25,1) [Aug 7 14:28:20.591] DEBUG[19660][C-00000001] pbx.c: Launching 'Stasis' [Aug 7 14:28:20.591] VERBOSE[19660][C-00000001] pbx.c: Executing [25@internal-device-custom:1] Stasis("SIP/322-00000000", "issues,start") in new stack [Aug 7 14:28:20.591] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 505 [Aug 7 14:28:20.591] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 505 [Aug 7 14:28:20.591] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 481 [Aug 7 14:28:20.591] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 481 [Aug 7 14:28:20.591] DEBUG[19660][C-00000001] stasis/app.c: Channel '1533644900.0' is 1 interested in issues [Aug 7 14:28:20.591] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 446 [Aug 7 14:28:20.591] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 446 [Aug 7 14:28:20.595] DEBUG[19662] http.c: HTTP opening session. Top level [Aug 7 14:28:20.595] DEBUG[19662] http.c: HTTP Request URI is /ari/channels/1533644900.0/answer [Aug 7 14:28:20.595] DEBUG[19662] http.c: match request [ari/channels/1533644900.0/answer] with handler [httpstatus] len 10 [Aug 7 14:28:20.595] DEBUG[19662] http.c: match request [ari/channels/1533644900.0/answer] with handler [static] len 6 [Aug 7 14:28:20.595] DEBUG[19662] http.c: match request [ari/channels/1533644900.0/answer] with handler [ari] len 3 [Aug 7 14:28:20.595] DEBUG[19662] http.c: Match made with [ari] [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Finding handler for channels [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Checking playbacks [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Checking channels [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Got it! [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Finding handler for 1533644900.0 [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Checking create [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Checking channelId [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Got it! [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Finding handler for answer [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Checking continue [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Checking redirect [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Checking answer [Aug 7 14:28:20.595] DEBUG[19662] res_ari.c: Got it! [Aug 7 14:28:20.595] DEBUG[19662] res_stasis_answer.c: 1533644900.0: Sending answer command [Aug 7 14:28:20.792] DEBUG[19660][C-00000001] res_stasis_answer.c: 1533644900.0: Answering [Aug 7 14:28:20.792] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 447 [Aug 7 14:28:20.792] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 447 [Aug 7 14:28:20.792] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 434 [Aug 7 14:28:20.792] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 434 [Aug 7 14:28:20.792] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - 322 [Aug 7 14:28:20.792] DEBUG[18805] chan_sip.c: Checking device state for peer 322 [Aug 7 14:28:20.792] DEBUG[18805] devicestate.c: Changing state for SIP/322 - state 2 (In use) [Aug 7 14:28:20.792] DEBUG[19660][C-00000001] chan_sip.c: SIP answering channel: SIP/322-00000000 [Aug 7 14:28:20.792] DEBUG[19660][C-00000001] res_rtp_asterisk.c: Setting the marker bit due to a source update [Aug 7 14:28:20.792] DEBUG[19660][C-00000001] chan_sip.c: ** Our capability: (alaw) Video flag: True Text flag: True [Aug 7 14:28:20.792] DEBUG[19660][C-00000001] chan_sip.c: ** Our prefcodec: (nothing) [Aug 7 14:28:20.792] DEBUG[19660][C-00000001] chan_sip.c: -- Done with adding codecs to SDP [Aug 7 14:28:20.792] DEBUG[19660][C-00000001] chan_sip.c: Setting framing on incoming call: 20 [Aug 7 14:28:20.792] DEBUG[19660][C-00000001] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [Aug 7 14:28:20.792] DEBUG[19660][C-00000001] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 172.21.254.254:5063 [Aug 7 14:28:20.792] DEBUG[19662] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:28:20.794] DEBUG[19662] http.c: HTTP Request URI is /ari/bridges [Aug 7 14:28:20.794] DEBUG[19662] http.c: match request [ari/bridges] with handler [httpstatus] len 10 [Aug 7 14:28:20.794] DEBUG[19662] http.c: match request [ari/bridges] with handler [static] len 6 [Aug 7 14:28:20.794] DEBUG[19662] http.c: match request [ari/bridges] with handler [ari] len 3 [Aug 7 14:28:20.794] DEBUG[19662] http.c: Match made with [ari] [Aug 7 14:28:20.794] DEBUG[19662] http.c: HTTP consuming request body [Aug 7 14:28:20.794] DEBUG[19662] res_ari.c: Finding handler for bridges [Aug 7 14:28:20.794] DEBUG[19662] res_ari.c: Checking playbacks [Aug 7 14:28:20.794] DEBUG[19662] res_ari.c: Checking channels [Aug 7 14:28:20.794] DEBUG[19662] res_ari.c: Checking asterisk [Aug 7 14:28:20.794] DEBUG[19662] res_ari.c: Checking events [Aug 7 14:28:20.794] DEBUG[19662] res_ari.c: Checking bridges [Aug 7 14:28:20.794] DEBUG[19662] res_ari.c: Got it! [Aug 7 14:28:20.794] DEBUG[19662] dahdi/bridge_native_dahdi.c: Bridge bridge_5b699064c1cc4: Cannot use native DAHDI. Must have two channels. [Aug 7 14:28:20.794] DEBUG[19662] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:28:20.794] DEBUG[19662] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:28:20.794] DEBUG[19662] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4' can not use native RTP bridge as two channels are required [Aug 7 14:28:20.794] DEBUG[19662] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 7 14:28:20.794] DEBUG[19662] bridge.c: Chose bridge technology simple_bridge [Aug 7 14:28:20.794] DEBUG[19662] bridge.c: Bridge bridge_5b699064c1cc4: calling simple_bridge technology constructor [Aug 7 14:28:20.794] DEBUG[19662] bridge.c: Bridge bridge_5b699064c1cc4: calling simple_bridge technology start [Aug 7 14:28:20.794] DEBUG[19662] http.c: HTTP keeping session open. status_code:200 [Aug 7 14:28:20.795] DEBUG[19662] http.c: HTTP Request URI is /ari/bridges/bridge_5b699064c1cc4/addChannel [Aug 7 14:28:20.795] DEBUG[19662] http.c: match request [ari/bridges/bridge_5b699064c1cc4/addChannel] with handler [httpstatus] len 10 [Aug 7 14:28:20.795] DEBUG[19662] http.c: match request [ari/bridges/bridge_5b699064c1cc4/addChannel] with handler [static] len 6 [Aug 7 14:28:20.795] DEBUG[19662] http.c: match request [ari/bridges/bridge_5b699064c1cc4/addChannel] with handler [ari] len 3 [Aug 7 14:28:20.795] DEBUG[19662] http.c: Match made with [ari] [Aug 7 14:28:20.795] DEBUG[19662] http.c: HTTP consuming request body [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Finding handler for bridges [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Checking playbacks [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Checking channels [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Checking asterisk [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Checking events [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Checking bridges [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Got it! [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Finding handler for bridge_5b699064c1cc4 [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Checking bridgeId [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Got it! [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Finding handler for addChannel [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Checking addChannel [Aug 7 14:28:20.795] DEBUG[19662] res_ari.c: Got it! [Aug 7 14:28:20.795] DEBUG[19662] stasis/control.c: 1533644900.0: Sending channel add_to_bridge command [Aug 7 14:28:20.891] DEBUG[18944] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 200 ms (t1 100 ms (Retrans id #38)) [Aug 7 14:28:20.891] DEBUG[18944] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 172.21.254.254:5063 [Aug 7 14:28:20.993] DEBUG[19660][C-00000001] bridge_roles.c: Roles did not exist on channel SIP/322-00000000 [Aug 7 14:28:20.993] DEBUG[19660][C-00000001] stasis/control.c: 1533644900.0: Adding to bridge bridge_5b699064c1cc4 [Aug 7 14:28:20.993] DEBUG[19660][C-00000001] stasis/app.c: Bridge 'bridge_5b699064c1cc4' is 1 interested in issues [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] bridge_channel.c: Bridge bridge_5b699064c1cc4: 0x7f7fdc005108(SIP/322-00000000) is joining [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] bridge_channel.c: Bridge bridge_5b699064c1cc4: pushing 0x7f7fdc005108(SIP/322-00000000) [Aug 7 14:28:20.993] VERBOSE[19663][C-00000001] bridge_channel.c: Channel SIP/322-00000000 joined 'simple_bridge' stasis-bridge [Aug 7 14:28:20.993] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 640 [Aug 7 14:28:20.993] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 640 [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] dahdi/bridge_native_dahdi.c: Bridge bridge_5b699064c1cc4: Cannot use native DAHDI. Must have two channels. [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4' can not use native RTP bridge as two channels are required [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] bridge.c: Chose bridge technology simple_bridge [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4 is already using the new technology. [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: 0x7f7fdc005108(SIP/322-00000000) is joining simple_bridge technology [Aug 7 14:28:20.993] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Changing ssrc from 1585721946 to 135136717 due to a source change [Aug 7 14:28:20.993] DEBUG[19660][C-00000001] stasis/app.c: Bridge 'bridge_5b699064c1cc4' is 2 interested in issues [Aug 7 14:28:20.993] DEBUG[19662] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:28:20.994] DEBUG[19662] http.c: HTTP Request URI is /ari/channels [Aug 7 14:28:20.994] DEBUG[19662] http.c: match request [ari/channels] with handler [httpstatus] len 10 [Aug 7 14:28:20.994] DEBUG[19662] http.c: match request [ari/channels] with handler [static] len 6 [Aug 7 14:28:20.994] DEBUG[19662] http.c: match request [ari/channels] with handler [ari] len 3 [Aug 7 14:28:20.994] DEBUG[19662] http.c: Match made with [ari] [Aug 7 14:28:20.994] DEBUG[19662] http.c: HTTP consuming request body [Aug 7 14:28:20.994] DEBUG[19662] res_ari.c: Finding handler for channels [Aug 7 14:28:20.994] DEBUG[19662] res_ari.c: Checking playbacks [Aug 7 14:28:20.994] DEBUG[19662] res_ari.c: Checking channels [Aug 7 14:28:20.994] DEBUG[19662] res_ari.c: Got it! [Aug 7 14:28:20.994] DEBUG[19662] chan_sip.c: Asked to create a SIP channel with formats: (slin) [Aug 7 14:28:20.994] DEBUG[19662] chan_sip.c: Allocating new SIP dialog for 665a07806ff4ea917e55101b1a257e2f@95.80.200.221:5060 - INVITE (No RTP) [Aug 7 14:28:20.994] DEBUG[19662] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f7fd8009f68' [Aug 7 14:28:20.994] DEBUG[19662] res_rtp_asterisk.c: Allocated port 19462 for RTP instance '0x7f7fd8009f68' [Aug 7 14:28:20.994] DEBUG[19662] rtp_engine.c: RTP instance '0x7f7fd8009f68' is setup and ready to go [Aug 7 14:28:20.994] DEBUG[19662] netsock2.c: Splitting 'stasis' into... [Aug 7 14:28:20.994] DEBUG[19662] netsock2.c: ...host 'stasis' and port ''. [Aug 7 14:28:20.994] DEBUG[19662] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f7fd8009f68' [Aug 7 14:28:20.994] VERBOSE[19662] netsock2.c: Using SIP RTP CoS mark 5 [Aug 7 14:28:20.994] DEBUG[19662] chan_sip.c: Setting NAT on RTP to On [Aug 7 14:28:20.994] DEBUG[19662] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:28:20.994] DEBUG[19662] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:20.994] DEBUG[19662] chan_sip.c: Setting NAT on RTP to On [Aug 7 14:28:20.994] DEBUG[19662] chan_sip.c: SIP call-id changed from '665a07806ff4ea917e55101b1a257e2f@95.80.200.221:5060' to '1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060' [Aug 7 14:28:20.994] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 240 [Aug 7 14:28:20.994] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 240 [Aug 7 14:28:20.994] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 442 [Aug 7 14:28:20.994] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 442 [Aug 7 14:28:20.994] DEBUG[19662] channel.c: Channel 0x7f7fd800dd48 'SIP/611-00000001' allocated [Aug 7 14:28:20.995] DEBUG[19662] chan_sip.c: *** Our native formats are (alaw) [Aug 7 14:28:20.995] DEBUG[19662] chan_sip.c: *** Joint capabilities are (nothing) [Aug 7 14:28:20.995] DEBUG[19662] chan_sip.c: *** Our capabilities are (alaw) [Aug 7 14:28:20.995] DEBUG[19662] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Aug 7 14:28:20.995] DEBUG[19662] chan_sip.c: *** Our preferred formats from the incoming channel are (slin) [Aug 7 14:28:20.995] DEBUG[19662] chan_sip.c: This channel will not be able to handle video. [Aug 7 14:28:20.995] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 526 [Aug 7 14:28:20.995] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 526 [Aug 7 14:28:20.995] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 506 [Aug 7 14:28:20.995] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 506 [Aug 7 14:28:20.995] DEBUG[19662] res_stasis.c: issues: Subscribing to 1533644900.1 [Aug 7 14:28:20.995] DEBUG[19662] stasis/app.c: Channel '1533644900.1' is 1 interested in issues [Aug 7 14:28:20.995] DEBUG[19662] http.c: HTTP keeping session open. status_code:200 [Aug 7 14:28:20.995] DEBUG[19664] chan_sip.c: Outgoing Call for 611 [Aug 7 14:28:20.995] DEBUG[19664] chan_sip.c: Updating call counter for outgoing call [Aug 7 14:28:20.995] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:28:20.995] DEBUG[18805] chan_sip.c: Checking device state for peer 611 [Aug 7 14:28:20.995] DEBUG[18805] devicestate.c: Changing state for SIP/611 - state 6 (Ringing) [Aug 7 14:28:20.995] DEBUG[18811] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:28:20.995] DEBUG[18811] devicestate.c: Checking provider Custom with Custom [Aug 7 14:28:20.995] DEBUG[18811] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:28:20.995] DEBUG[18811] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:28:20.995] DEBUG[18811] devicestate.c: Checking provider Custom with Custom [Aug 7 14:28:20.995] DEBUG[18811] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:28:20.995] DEBUG[19664] chan_sip.c: ** Our capability: (alaw) Video flag: False Text flag: False [Aug 7 14:28:20.995] DEBUG[19664] chan_sip.c: ** Our prefcodec: (slin) [Aug 7 14:28:20.995] DEBUG[19664] chan_sip.c: -- Done with adding codecs to SDP [Aug 7 14:28:20.995] DEBUG[19664] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [Aug 7 14:28:20.995] DEBUG[19664] chan_sip.c: Initializing initreq for method INVITE - callid 1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060 [Aug 7 14:28:20.995] DEBUG[19664] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:28:20.995] VERBOSE[19664] dial.c: Called 611 [Aug 7 14:28:20.995] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:28:20.995] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:28:20.996] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 463 [Aug 7 14:28:20.996] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 463 [Aug 7 14:28:20.997] DEBUG[19663][C-00000001] res_rtp_asterisk.c: 0x7f7fb000c830 -- Received RTP packet from 172.21.254.254:11790, dropping due to strict RTP protection. Qualifying new stream. [Aug 7 14:28:21.001] DEBUG[18944] chan_sip.c: = Looking for Call ID: 1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060 (Checking To) --From tag as542355a5 --To-tag [Aug 7 14:28:21.001] DEBUG[18944] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060' Request 102: Found [Aug 7 14:28:21.001] DEBUG[18944] chan_sip.c: SIP response 100 to standard invite [Aug 7 14:28:21.005] DEBUG[18944] chan_sip.c: = Looking for Call ID: 3890068728@10.255.255.157 (Checking From) --From tag 4052487425 --To-tag as7131796c [Aug 7 14:28:21.005] DEBUG[18944][C-00000001] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 7 14:28:21.006] DEBUG[18944][C-00000001] chan_sip.c: Stopping retransmission on '3890068728@10.255.255.157' of Response 2: Match Found [Aug 7 14:28:21.018] VERBOSE[19663][C-00000001] res_rtp_asterisk.c: 0x7f7fb000c830 -- Strict RTP qualifying stream type: audio [Aug 7 14:28:21.018] DEBUG[19663][C-00000001] res_rtp_asterisk.c: 0x7f7fb000c830 -- Received RTP packet from 172.21.254.254:11790, dropping due to strict RTP protection. Will switch to it in 3 packets. [Aug 7 14:28:21.038] DEBUG[19663][C-00000001] res_rtp_asterisk.c: 0x7f7fb000c830 -- Received RTP packet from 172.21.254.254:11790, dropping due to strict RTP protection. Will switch to it in 2 packets. [Aug 7 14:28:21.046] DEBUG[18944] chan_sip.c: = Looking for Call ID: 1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060 (Checking To) --From tag as542355a5 --To-tag YgfK1gM0czBUUeEO341.HVXrZoRK-9WY [Aug 7 14:28:21.046] DEBUG[18944] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060' Request 102: Found [Aug 7 14:28:21.046] DEBUG[18944] chan_sip.c: SIP response 180 to standard invite [Aug 7 14:28:21.046] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:28:21.046] DEBUG[18805] chan_sip.c: Checking device state for peer 611 [Aug 7 14:28:21.046] DEBUG[18805] devicestate.c: Changing state for SIP/611 - state 6 (Ringing) [Aug 7 14:28:21.046] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 448 [Aug 7 14:28:21.046] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:28:21.046] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 448 [Aug 7 14:28:21.046] DEBUG[18805] chan_sip.c: Checking device state for peer 611 [Aug 7 14:28:21.046] DEBUG[18805] devicestate.c: Changing state for SIP/611 - state 6 (Ringing) [Aug 7 14:28:21.046] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 435 [Aug 7 14:28:21.046] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 435 [Aug 7 14:28:21.046] DEBUG[18811] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:28:21.046] DEBUG[18811] devicestate.c: Checking provider Custom with Custom [Aug 7 14:28:21.046] VERBOSE[19664] dial.c: SIP/611-00000001 is ringing [Aug 7 14:28:21.046] DEBUG[18811] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:28:21.046] DEBUG[18811] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:28:21.046] DEBUG[18811] devicestate.c: Checking provider Custom with Custom [Aug 7 14:28:21.046] DEBUG[18811] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:28:21.046] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 486 [Aug 7 14:28:21.046] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 486 [Aug 7 14:28:21.046] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 473 [Aug 7 14:28:21.046] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 473 [Aug 7 14:28:21.058] DEBUG[19663][C-00000001] res_rtp_asterisk.c: 0x7f7fb000c830 -- Received RTP packet from 172.21.254.254:11790, dropping due to strict RTP protection. Will switch to it in 1 packets. [Aug 7 14:28:21.075] DEBUG[18944] chan_sip.c: = Looking for Call ID: 3890068728@10.255.255.157 (Checking From) --From tag 4052487425 --To-tag as7131796c [Aug 7 14:28:21.075] DEBUG[18944][C-00000001] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 7 14:28:21.078] VERBOSE[19663][C-00000001] res_rtp_asterisk.c: 0x7f7fb000c830 -- Strict RTP switching source address to 172.21.254.254:11790 [Aug 7 14:28:21.078] DEBUG[19663][C-00000001] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:28:21.078] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f7fb00017a8' [Aug 7 14:28:23.463] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 48 bytes from 172.21.254.254:11791 [Aug 7 14:28:24.399] DEBUG[18944] chan_sip.c: = Looking for Call ID: 1998117674@192.168.10.120 (Checking From) --From tag 1179217472 --To-tag [Aug 7 14:28:24.399] DEBUG[18944] acl.c: For destination '212.24.153.186', our source address is '95.80.200.221'. [Aug 7 14:28:24.399] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:24.399] DEBUG[18944] netsock2.c: Splitting '192.168.10.120:5062' into... [Aug 7 14:28:24.399] DEBUG[18944] netsock2.c: ...host '192.168.10.120' and port '5062'. [Aug 7 14:28:24.399] DEBUG[18944] chan_sip.c: NAT detected for 192.168.10.120 / 212.24.153.186 [Aug 7 14:28:24.399] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 1998117674@192.168.10.120 - REGISTER (No RTP) [Aug 7 14:28:24.399] DEBUG[18944] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Aug 7 14:28:24.399] DEBUG[18944] netsock2.c: Splitting '192.168.10.120:5062' into... [Aug 7 14:28:24.399] DEBUG[18944] netsock2.c: ...host '192.168.10.120' and port '5062'. [Aug 7 14:28:24.399] DEBUG[18944] chan_sip.c: NAT detected for 192.168.10.120 / 212.24.153.186 [Aug 7 14:28:24.399] DEBUG[18944] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:28:24.399] DEBUG[18944] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:28:24.399] DEBUG[18944] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 212.24.153.186:5062 [Aug 7 14:28:24.497] DEBUG[18944] chan_sip.c: = Looking for Call ID: 1998117674@192.168.10.120 (Checking From) --From tag 1179217472 --To-tag [Aug 7 14:28:24.497] DEBUG[18944] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Aug 7 14:28:24.497] DEBUG[18944] netsock2.c: Splitting '192.168.10.120:5062' into... [Aug 7 14:28:24.497] DEBUG[18944] netsock2.c: ...host '192.168.10.120' and port '5062'. [Aug 7 14:28:24.497] DEBUG[18944] chan_sip.c: NAT detected for 192.168.10.120 / 212.24.153.186 [Aug 7 14:28:24.497] DEBUG[18944] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:28:24.497] DEBUG[18944] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:28:24.497] DEBUG[18944] chan_sip.c: Store REGISTER's src-IP:port for call routing. [Aug 7 14:28:24.497] DEBUG[18944] chan_sip.c: build_path: do not use Path headers [Aug 7 14:28:24.497] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 5d8a90207c6dc39514516b8f2df20f1f@95.80.200.221:5060 - OPTIONS (No RTP) [Aug 7 14:28:24.497] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 234 [Aug 7 14:28:24.497] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 234 [Aug 7 14:28:24.497] DEBUG[18944] acl.c: For destination '212.24.153.186', our source address is '95.80.200.221'. [Aug 7 14:28:24.497] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:24.497] DEBUG[18944] chan_sip.c: SIP call-id changed from '5d8a90207c6dc39514516b8f2df20f1f@95.80.200.221:5060' to '54346508419048f334ee0361283b3e7b@95.80.200.221:5060' [Aug 7 14:28:24.497] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 299 [Aug 7 14:28:24.497] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 299 [Aug 7 14:28:24.497] DEBUG[18944] chan_sip.c: Initializing initreq for method OPTIONS - callid 54346508419048f334ee0361283b3e7b@95.80.200.221:5060 [Aug 7 14:28:24.497] DEBUG[18944] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 212.24.153.186:5062 [Aug 7 14:28:24.497] VERBOSE[18944] chan_sip.c: Saved useragent "Well T22 hw5.0.0.60 fw7.61.9.5 00:15:65:56:b5:8b" for peer rozbitywell [Aug 7 14:28:24.497] DEBUG[18944] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 212.24.153.186:5062 [Aug 7 14:28:24.497] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - rozbitywell [Aug 7 14:28:24.497] DEBUG[18805] chan_sip.c: Checking device state for peer rozbitywell [Aug 7 14:28:24.497] DEBUG[18805] devicestate.c: Changing state for SIP/rozbitywell - state 1 (Not in use) [Aug 7 14:28:24.525] DEBUG[18944] chan_sip.c: = Looking for Call ID: 54346508419048f334ee0361283b3e7b@95.80.200.221:5060 (Checking To) --From tag as44ccc61a --To-tag 180568780 [Aug 7 14:28:24.525] DEBUG[18944] chan_sip.c: Stopping retransmission on '54346508419048f334ee0361283b3e7b@95.80.200.221:5060' of Request 102: Match Found [Aug 7 14:28:24.525] DEBUG[18944] chan_sip.c: Destroying SIP dialog 54346508419048f334ee0361283b3e7b@95.80.200.221:5060 [Aug 7 14:28:25.599] VERBOSE[19663][C-00000001] res_rtp_asterisk.c: 0x7f7fb000c830 -- Strict RTP learning complete - Locking on source address 172.21.254.254:11790 [Aug 7 14:28:27.840] DEBUG[18944] netsock2.c: Splitting 'proxy.daktela.com' into... [Aug 7 14:28:27.840] DEBUG[18944] netsock2.c: ...host 'proxy.daktela.com' and port ''. [Aug 7 14:28:27.840] DEBUG[18944] dnsmgr.c: doing dnsmgr_lookup for 'proxy.daktela.com' [Aug 7 14:28:28.463] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 48 bytes from 172.21.254.254:11791 [Aug 7 14:28:29.843] DEBUG[18944] netsock2.c: Splitting 'proxy.daktela.com' into... [Aug 7 14:28:29.843] DEBUG[18944] netsock2.c: ...host 'proxy.daktela.com' and port ''. [Aug 7 14:28:30.862] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 0a9b28d07a4a64df1b8dc2e42cdf0f44@95.80.200.221 - REGISTER (No RTP) [Aug 7 14:28:30.862] DEBUG[18944] acl.c: For destination 'test.test.com', our source address is '95.80.200.221'. [Aug 7 14:28:30.862] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:30.862] DEBUG[18944] netsock2.c: Splitting 'proxy.daktela.com' into... [Aug 7 14:28:30.862] DEBUG[18944] netsock2.c: ...host 'proxy.daktela.com' and port ''. [Aug 7 14:28:30.862] DEBUG[18944] netsock2.c: Splitting 'proxy.daktela.com' into... [Aug 7 14:28:30.862] DEBUG[18944] netsock2.c: ...host 'proxy.daktela.com' and port ''. [Aug 7 14:28:30.862] DEBUG[18944] netsock2.c: Splitting 'proxy.daktela.com' into... [Aug 7 14:28:30.862] DEBUG[18944] netsock2.c: ...host 'proxy.daktela.com' and port ''. [Aug 7 14:28:30.862] DEBUG[18944] chan_sip.c: Initializing initreq for method REGISTER - callid 0a9b28d07a4a64df1b8dc2e42cdf0f44@95.80.200.221 [Aug 7 14:28:30.862] DEBUG[18944] chan_sip.c: REGISTER attempt 1 to 20170309@proxy.daktela.com [Aug 7 14:28:30.862] DEBUG[18944] chan_sip.c: Trying to put 'REGISTER si' onto UDP socket destined for test.test.com:5060 [Aug 7 14:28:30.862] DEBUG[18944] chan_sip.c: Scheduled a registration timeout for proxy.daktela.com id #17 [Aug 7 14:28:30.862] DEBUG[18944] chan_sip.c: = Looking for Call ID: 0a9b28d07a4a64df1b8dc2e42cdf0f44@95.80.200.221 (Checking To) --From tag as006844ad --To-tag as03d158de [Aug 7 14:28:30.862] DEBUG[18944] chan_sip.c: Stopping retransmission on '0a9b28d07a4a64df1b8dc2e42cdf0f44@95.80.200.221' of Request 104: Match Found [Aug 7 14:28:30.862] DEBUG[18944] netsock2.c: Splitting 'proxy.daktela.com' into... [Aug 7 14:28:30.862] DEBUG[18944] netsock2.c: ...host 'proxy.daktela.com' and port ''. [Aug 7 14:28:30.862] DEBUG[18944] dnsmgr.c: doing dnsmgr_lookup for 'proxy.daktela.com' [Aug 7 14:28:30.974] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11791 [Aug 7 14:28:30.991] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 48 bytes from 172.21.254.254:11791 [Aug 7 14:28:31.005] DEBUG[19662] iostream.c: TCP timeout reading data [Aug 7 14:28:31.005] DEBUG[19662] http.c: HTTP closing session. Top level [Aug 7 14:28:32.265] DEBUG[19664] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.21.254.254:4007 [Aug 7 14:28:32.265] DEBUG[19664] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.21.254.254:4007 [Aug 7 14:28:32.396] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.408] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.431] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.454] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.465] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.488] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.512] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.535] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.547] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.570] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.593] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.604] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.628] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.651] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.674] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.686] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.709] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.732] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.755] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.767] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.789] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.813] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.825] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.848] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.866] DEBUG[18944] netsock2.c: Splitting 'proxy.daktela.com' into... [Aug 7 14:28:32.866] DEBUG[18944] netsock2.c: ...host 'proxy.daktela.com' and port ''. [Aug 7 14:28:32.871] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.894] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.905] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.929] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.953] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.964] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:32.987] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.010] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.033] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.044] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.068] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.091] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.114] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.126] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.149] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.172] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.183] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.207] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.237] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.256] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.271] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.291] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.314] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.325] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.348] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.371] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.395] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.407] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.430] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.453] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.463] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 48 bytes from 172.21.254.254:11791 [Aug 7 14:28:33.475] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.488] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.511] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.534] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.545] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.569] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.592] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.614] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.626] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.650] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.672] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.684] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.707] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.731] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.754] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.765] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.789] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.812] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.835] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.846] DEBUG[19664] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. [Aug 7 14:28:33.867] DEBUG[18944] netsock2.c: Splitting 'proxy.daktela.com' into... [Aug 7 14:28:33.867] DEBUG[18944] netsock2.c: ...host 'proxy.daktela.com' and port ''. [Aug 7 14:28:33.867] DEBUG[18944] netsock2.c: Splitting 'proxy.daktela.com' into... [Aug 7 14:28:33.867] DEBUG[18944] netsock2.c: ...host 'proxy.daktela.com' and port ''. [Aug 7 14:28:33.867] DEBUG[18944] netsock2.c: Splitting 'proxy.daktela.com' into... [Aug 7 14:28:33.867] DEBUG[18944] netsock2.c: ...host 'proxy.daktela.com' and port ''. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Initializing already initialized SIP dialog 0a9b28d07a4a64df1b8dc2e42cdf0f44@95.80.200.221 (presumably reinvite) [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: REGISTER attempt 2 to 20170309@proxy.daktela.com [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Trying to put 'REGISTER si' onto UDP socket destined for test.test.com:5060 [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: = Looking for Call ID: 1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060 (Checking To) --From tag as542355a5 --To-tag YgfK1gM0czBUUeEO341.HVXrZoRK-9WY [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Acked pending invite 102 [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Stopping retransmission on '1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060' of Request 102: Match Found [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: SIP response 200 to standard invite [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing session-level SDP o=- 3742633700 3742633701 IN IP4 10.255.255.167... OK. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing session-level SDP s=pjmedia... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing session-level SDP b=AS:117... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing session-level SDP a=X-nat:0... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.867] DEBUG[18944] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f7f8e6ced00 [Aug 7 14:28:33.867] DEBUG[18944] netsock2.c: Splitting '10.255.255.167' into... [Aug 7 14:28:33.867] DEBUG[18944] netsock2.c: ...host '10.255.255.167' and port ''. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP c=IN IP4 10.255.255.167... OK. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP b=TIAS:96000... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP a=rtcp:4007 IN IP4 10.255.255.167... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.867] DEBUG[18944] acl.c: For destination '10.255.255.167', our source address is '95.80.200.221'. [Aug 7 14:28:33.867] DEBUG[18944] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f7fd8009f68' [Aug 7 14:28:33.867] VERBOSE[18944] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Strict RTP learning after remote address set to: 10.255.255.167:4006 [Aug 7 14:28:33.867] DEBUG[18944] rtp_engine.c: Copying tx payload mapping 8 (0x7f7fb0000e70) from 0x7f7f8e6ced00 to 0x7f7fd800a140 [Aug 7 14:28:33.867] DEBUG[18944] rtp_engine.c: Copying tx payload mapping 101 (0x7f7fb0000c40) from 0x7f7f8e6ced00 to 0x7f7fd800a140 [Aug 7 14:28:33.867] DEBUG[18944] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f7fd8009f68' [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: We're settling with these formats: (alaw) [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: We have an owner, now see if we need to change this call [Aug 7 14:28:33.867] DEBUG[18944] channel.c: Channel SIP/611-00000001 setting read format path: alaw -> alaw [Aug 7 14:28:33.867] DEBUG[18944] channel.c: Channel SIP/611-00000001 setting write format path: alaw -> alaw [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Updating call counter for outgoing call [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Trying to put 'ACK sip:611' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:28:33.867] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:28:33.867] DEBUG[18805] chan_sip.c: Checking device state for peer 611 [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: = Looking for Call ID: 1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060 (Checking To) --From tag as542355a5 --To-tag YgfK1gM0czBUUeEO341.HVXrZoRK-9WY [Aug 7 14:28:33.867] DEBUG[18805] devicestate.c: Changing state for SIP/611 - state 2 (In use) [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Stopping retransmission on '1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060' of Request 102: Match Not Found [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Trying to put 'ACK sip:611' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:28:33.867] DEBUG[18811] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:28:33.867] DEBUG[18811] devicestate.c: Checking provider Custom with Custom [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: = Looking for Call ID: 1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060 (Checking To) --From tag as542355a5 --To-tag YgfK1gM0czBUUeEO341.HVXrZoRK-9WY [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Stopping retransmission on '1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060' of Request 102: Match Not Found [Aug 7 14:28:33.867] DEBUG[18944] chan_sip.c: Trying to put 'ACK sip:611' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:28:33.867] DEBUG[18811] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:28:33.867] DEBUG[18811] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:28:33.867] DEBUG[18811] devicestate.c: Checking provider Custom with Custom [Aug 7 14:28:33.867] DEBUG[18811] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:28:33.867] VERBOSE[19664] dial.c: SIP/611-00000001 answered [Aug 7 14:28:33.867] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 443 [Aug 7 14:28:33.867] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 443 [Aug 7 14:28:33.867] VERBOSE[19664] ari/resource_channels.c: Launching Stasis(issues,second,1533644900.0,bridge_5b699064c1cc4) on SIP/611-00000001 [Aug 7 14:28:33.867] DEBUG[19664] stasis/app.c: Channel '1533644900.1' is 2 interested in issues [Aug 7 14:28:33.867] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 480 [Aug 7 14:28:33.867] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 480 [Aug 7 14:28:33.867] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 475 [Aug 7 14:28:33.867] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 475 [Aug 7 14:28:33.868] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 430 [Aug 7 14:28:33.868] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 430 [Aug 7 14:28:33.868] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 467 [Aug 7 14:28:33.868] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 467 [Aug 7 14:28:33.868] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 462 [Aug 7 14:28:33.868] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 462 [Aug 7 14:28:33.868] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 479 [Aug 7 14:28:33.868] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 479 [Aug 7 14:28:33.868] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:28:33.868] DEBUG[18805] chan_sip.c: Checking device state for peer 611 [Aug 7 14:28:33.868] DEBUG[18805] devicestate.c: Changing state for SIP/611 - state 2 (In use) [Aug 7 14:28:33.868] DEBUG[19673] http.c: HTTP opening session. Top level [Aug 7 14:28:33.868] DEBUG[18944] chan_sip.c: = Looking for Call ID: 34023d0225aa15730ebd5a6b1d40ef05@test.test.com:5060 (Checking From) --From tag as1526cb36 --To-tag [Aug 7 14:28:33.868] DEBUG[19673] http.c: HTTP Request URI is /ari/bridges/bridge_5b699064c1cc4/addChannel [Aug 7 14:28:33.868] DEBUG[18944] acl.c: For destination 'test.test.com', our source address is '95.80.200.221'. [Aug 7 14:28:33.868] DEBUG[19673] http.c: match request [ari/bridges/bridge_5b699064c1cc4/addChannel] with handler [httpstatus] len 10 [Aug 7 14:28:33.868] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:33.868] DEBUG[18944] netsock2.c: Splitting 'test.test.com:5060' into... [Aug 7 14:28:33.868] DEBUG[18944] netsock2.c: ...host 'test.test.com' and port '5060'. [Aug 7 14:28:33.868] DEBUG[19673] http.c: match request [ari/bridges/bridge_5b699064c1cc4/addChannel] with handler [static] len 6 [Aug 7 14:28:33.868] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 34023d0225aa15730ebd5a6b1d40ef05@test.test.com:5060 - OPTIONS (No RTP) [Aug 7 14:28:33.868] DEBUG[19673] http.c: match request [ari/bridges/bridge_5b699064c1cc4/addChannel] with handler [ari] len 3 [Aug 7 14:28:33.869] DEBUG[18944] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Aug 7 14:28:33.869] DEBUG[18944] netsock2.c: Splitting '95.80.200.221:5060' into... [Aug 7 14:28:33.869] DEBUG[18944] netsock2.c: ...host '95.80.200.221' and port ''. [Aug 7 14:28:33.869] DEBUG[18944] netsock2.c: Splitting 'test.test.com' into... [Aug 7 14:28:33.869] DEBUG[18944] netsock2.c: ...host 'test.test.com' and port ''. [Aug 7 14:28:33.868] DEBUG[19673] http.c: Match made with [ari] [Aug 7 14:28:33.869] DEBUG[18944] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for test.test.com:5060 [Aug 7 14:28:33.869] DEBUG[19673] http.c: HTTP consuming request body [Aug 7 14:28:33.869] DEBUG[18944] chan_sip.c: = Looking for Call ID: 0a9b28d07a4a64df1b8dc2e42cdf0f44@95.80.200.221 (Checking To) --From tag as006844ad --To-tag as03d158de [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Finding handler for bridges [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Checking playbacks [Aug 7 14:28:33.869] DEBUG[18944] chan_sip.c: Stopping retransmission on '0a9b28d07a4a64df1b8dc2e42cdf0f44@95.80.200.221' of Request 105: Match Found [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Checking channels [Aug 7 14:28:33.869] DEBUG[18944] chan_sip.c: Registration successful [Aug 7 14:28:33.869] DEBUG[18944] chan_sip.c: Cancelling timeout 17 [Aug 7 14:28:33.869] DEBUG[18944] chan_sip.c: Destroying SIP dialog 0a9b28d07a4a64df1b8dc2e42cdf0f44@95.80.200.221 [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Checking asterisk [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Checking events [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Checking bridges [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Got it! [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Finding handler for bridge_5b699064c1cc4 [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Checking bridgeId [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Got it! [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Finding handler for addChannel [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Checking addChannel [Aug 7 14:28:33.869] DEBUG[19673] res_ari.c: Got it! [Aug 7 14:28:33.869] DEBUG[19673] stasis/control.c: 1533644900.1: Sending channel add_to_bridge command [Aug 7 14:28:33.870] DEBUG[19664] bridge_roles.c: Roles did not exist on channel SIP/611-00000001 [Aug 7 14:28:33.870] DEBUG[19664] stasis/control.c: 1533644900.1: Adding to bridge bridge_5b699064c1cc4 [Aug 7 14:28:33.870] DEBUG[19664] stasis/app.c: Bridge 'bridge_5b699064c1cc4' is 3 interested in issues [Aug 7 14:28:33.870] DEBUG[19674] bridge_channel.c: Bridge bridge_5b699064c1cc4: 0x1b71a78(SIP/611-00000001) is joining [Aug 7 14:28:33.870] DEBUG[19674] bridge_channel.c: Bridge bridge_5b699064c1cc4: pushing 0x1b71a78(SIP/611-00000001) [Aug 7 14:28:33.870] VERBOSE[19674] bridge_channel.c: Channel SIP/611-00000001 joined 'simple_bridge' stasis-bridge [Aug 7 14:28:33.870] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 651 [Aug 7 14:28:33.870] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 651 [Aug 7 14:28:33.870] DEBUG[19674] dahdi/bridge_native_dahdi.c: Channel 'SIP/322-00000000' is not DAHDI. [Aug 7 14:28:33.870] DEBUG[19674] dahdi/bridge_native_dahdi.c: Bridge bridge_5b699064c1cc4: Cannot use native DAHDI. Channel 'SIP/322-00000000' not compatible. [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:28:33.870] DEBUG[19674] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Checking compatability for channels 'SIP/322-00000000' and 'SIP/611-00000001' [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Chose bridge technology native_rtp [Aug 7 14:28:33.870] VERBOSE[19674] bridge.c: Bridge bridge_5b699064c1cc4: switching from simple_bridge technology to native_rtp [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge bridge_5b699064c1cc4: calling native_rtp technology constructor [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge bridge_5b699064c1cc4: moving 0x7f7fdc005108(SIP/322-00000000) to dummy bridge temporarily [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge bridge_5b699064c1cc4: 0x7f7fdc005108(SIP/322-00000000) is leaving simple_bridge technology (dummy) [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge bridge_5b699064c1cc4: calling simple_bridge technology stop [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge bridge_5b699064c1cc4: 0x1b71a78(SIP/611-00000001) is joining native_rtp technology [Aug 7 14:28:33.870] DEBUG[19674] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Channel 'SIP/611-00000001' is joining bridge tech [Aug 7 14:28:33.870] DEBUG[19674] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Attaching hook data 0x7f7fa4001ef0 to 'SIP/611-00000001' [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge bridge_5b699064c1cc4: 0x7f7fdc005108(SIP/322-00000000) is joining native_rtp technology [Aug 7 14:28:33.870] DEBUG[19674] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Channel 'SIP/322-00000000' is joining bridge tech [Aug 7 14:28:33.870] DEBUG[19674] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Attaching hook data 0x7f7fa4001fa0 to 'SIP/322-00000000' [Aug 7 14:28:33.870] DEBUG[19674] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Tech starting 'SIP/611-00000001' and 'SIP/322-00000000' with target 'none' [Aug 7 14:28:33.870] VERBOSE[19674] bridge_native_rtp.c: Locally RTP bridged 'SIP/611-00000001' and 'SIP/322-00000000' in stack [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge bridge_5b699064c1cc4: calling native_rtp technology start [Aug 7 14:28:33.870] DEBUG[19674] bridge.c: Bridge bridge_5b699064c1cc4: calling simple_bridge technology destructor [Aug 7 14:28:33.870] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:28:33.870] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:28:33.870] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:28:33.870] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:28:33.870] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:28:33.870] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:28:33.870] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 490 [Aug 7 14:28:33.870] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 490 [Aug 7 14:28:33.871] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 493 [Aug 7 14:28:33.871] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 493 [Aug 7 14:28:33.871] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 480 [Aug 7 14:28:33.871] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 480 [Aug 7 14:28:33.871] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 533 [Aug 7 14:28:33.871] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 533 [Aug 7 14:28:33.871] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 520 [Aug 7 14:28:33.871] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 520 [Aug 7 14:28:33.871] DEBUG[19664] stasis/app.c: Bridge 'bridge_5b699064c1cc4' is 4 interested in issues [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] dahdi/bridge_native_dahdi.c: Channel 'SIP/611-00000001' is not DAHDI. [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] dahdi/bridge_native_dahdi.c: Bridge bridge_5b699064c1cc4: Cannot use native DAHDI. Channel 'SIP/611-00000001' not compatible. [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Checking compatability for channels 'SIP/611-00000001' and 'SIP/322-00000000' [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] bridge.c: Chose bridge technology native_rtp [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4 is already using the new technology. [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] chan_sip.c: ** Our capability: (alaw) Video flag: True Text flag: True [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] chan_sip.c: ** Our prefcodec: (nothing) [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] chan_sip.c: -- Done with adding codecs to SDP [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] chan_sip.c: Setting framing on incoming call: 20 [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] chan_sip.c: Initializing already initialized SIP dialog 3890068728@10.255.255.157 (presumably reinvite) [Aug 7 14:28:33.871] DEBUG[19663][C-00000001] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 172.21.254.254:5063 [Aug 7 14:28:33.871] DEBUG[18794] threadpool.c: Increasing threadpool stasis-core's size by 1 [Aug 7 14:28:33.871] DEBUG[19673] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:28:33.871] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:28:33.871] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:28:33.871] DEBUG[19673] http.c: HTTP Request URI is /ari/channels/1533644900.0/hold [Aug 7 14:28:33.871] DEBUG[19673] http.c: match request [ari/channels/1533644900.0/hold] with handler [httpstatus] len 10 [Aug 7 14:28:33.871] DEBUG[19673] http.c: match request [ari/channels/1533644900.0/hold] with handler [static] len 6 [Aug 7 14:28:33.871] DEBUG[19673] http.c: match request [ari/channels/1533644900.0/hold] with handler [ari] len 3 [Aug 7 14:28:33.871] DEBUG[19673] http.c: Match made with [ari] [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Finding handler for channels [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Checking playbacks [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Checking channels [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Got it! [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Finding handler for 1533644900.0 [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Checking create [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Checking channelId [Aug 7 14:28:33.871] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 490 [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Got it! [Aug 7 14:28:33.871] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 490 [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Finding handler for hold [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Checking continue [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Checking redirect [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Checking answer [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Checking ring [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Checking dtmf [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Checking mute [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Checking hold [Aug 7 14:28:33.871] DEBUG[19673] res_ari.c: Got it! [Aug 7 14:28:33.871] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 480 [Aug 7 14:28:33.871] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 480 [Aug 7 14:28:33.871] DEBUG[19660][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Tech stopping 'SIP/611-00000001' and 'SIP/322-00000000' with target 'SIP/322-00000000' [Aug 7 14:28:33.871] DEBUG[19660][C-00000001] bridge_native_rtp.c: Discontinued RTP bridging of 'SIP/611-00000001' and 'SIP/322-00000000' - media will flow through Asterisk core [Aug 7 14:28:33.871] DEBUG[19660][C-00000001] res_rtp_asterisk.c: Setting the marker bit due to a source update [Aug 7 14:28:33.872] VERBOSE[19660][C-00000001] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/322-00000000' [Aug 7 14:28:33.872] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 520 [Aug 7 14:28:33.872] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 520 [Aug 7 14:28:33.872] DEBUG[19660][C-00000001] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Aug 7 14:28:33.872] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 453 [Aug 7 14:28:33.872] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 453 [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 493 [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 493 [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 533 [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 533 [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 466 [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 466 [Aug 7 14:28:33.872] DEBUG[19674] res_rtp_asterisk.c: Changing ssrc from 382126930 to 1291281000 due to a source change [Aug 7 14:28:33.872] DEBUG[19674] dahdi/bridge_native_dahdi.c: Channel 'SIP/611-00000001' is not DAHDI. [Aug 7 14:28:33.872] DEBUG[19674] dahdi/bridge_native_dahdi.c: Bridge bridge_5b699064c1cc4: Cannot use native DAHDI. Channel 'SIP/611-00000001' not compatible. [Aug 7 14:28:33.872] DEBUG[19674] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:28:33.872] DEBUG[19674] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:28:33.872] DEBUG[19674] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Checking compatability for channels 'SIP/611-00000001' and 'SIP/322-00000000' [Aug 7 14:28:33.872] DEBUG[19674] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:28:33.872] DEBUG[19674] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [Aug 7 14:28:33.872] DEBUG[19674] bridge.c: Chose bridge technology native_rtp [Aug 7 14:28:33.872] DEBUG[19674] bridge.c: Bridge bridge_5b699064c1cc4 is already using the new technology. [Aug 7 14:28:33.872] DEBUG[19673] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:28:33.872] DEBUG[19673] http.c: HTTP Request URI is /ari/channels/1533644900.0/mute [Aug 7 14:28:33.872] DEBUG[19673] http.c: match request [ari/channels/1533644900.0/mute] with handler [httpstatus] len 10 [Aug 7 14:28:33.872] DEBUG[19673] http.c: match request [ari/channels/1533644900.0/mute] with handler [static] len 6 [Aug 7 14:28:33.872] DEBUG[19673] http.c: match request [ari/channels/1533644900.0/mute] with handler [ari] len 3 [Aug 7 14:28:33.872] DEBUG[19673] http.c: Match made with [ari] [Aug 7 14:28:33.872] DEBUG[19673] http.c: HTTP consuming request body [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Finding handler for channels [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Checking playbacks [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Checking channels [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Got it! [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Finding handler for 1533644900.0 [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Checking create [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Checking channelId [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Got it! [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Finding handler for mute [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Checking continue [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Checking redirect [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Checking answer [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Checking ring [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Checking dtmf [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Checking mute [Aug 7 14:28:33.872] DEBUG[19673] res_ari.c: Got it! [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:28:33.872] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:28:33.872] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:28:33.872] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:28:33.873] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:28:33.873] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:28:33.873] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 490 [Aug 7 14:28:33.873] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 490 [Aug 7 14:28:33.873] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 510 [Aug 7 14:28:33.873] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 510 [Aug 7 14:28:33.873] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 497 [Aug 7 14:28:33.873] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 497 [Aug 7 14:28:33.873] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 550 [Aug 7 14:28:33.873] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 550 [Aug 7 14:28:33.873] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 537 [Aug 7 14:28:33.873] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 537 [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] dahdi/bridge_native_dahdi.c: Channel 'SIP/611-00000001' is not DAHDI. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] dahdi/bridge_native_dahdi.c: Bridge bridge_5b699064c1cc4: Cannot use native DAHDI. Channel 'SIP/611-00000001' not compatible. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Checking compatability for channels 'SIP/611-00000001' and 'SIP/322-00000000' [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4' can not use native RTP bridge as channel 'SIP/322-00000000' has features which prevent it [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Chose bridge technology simple_bridge [Aug 7 14:28:33.873] VERBOSE[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: switching from native_rtp technology to simple_bridge [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: calling simple_bridge technology constructor [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: moving 0x1b71a78(SIP/611-00000001) to dummy bridge temporarily [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: moving 0x7f7fdc005108(SIP/322-00000000) to dummy bridge temporarily [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: 0x1b71a78(SIP/611-00000001) is leaving native_rtp technology (dummy) [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Channel 'SIP/611-00000001' is leaving bridge tech [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Detaching hook data 0x7f7fa4003140 from 'SIP/611-00000001' [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Tech stopping 'SIP/611-00000001' and 'SIP/322-00000000' with target 'none' [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge_native_rtp.c: Destroying channel tech_pvt data 0x7f7fa4001ef0 [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: 0x7f7fdc005108(SIP/322-00000000) is leaving native_rtp technology (dummy) [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Channel 'SIP/322-00000000' is leaving bridge tech [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Detaching hook data 0x7f7fa40013c0 from 'SIP/322-00000000' [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge_native_rtp.c: Destroying channel tech_pvt data 0x7f7fa4001fa0 [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: calling native_rtp technology stop [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: 0x1b71a78(SIP/611-00000001) is joining simple_bridge technology [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] channel.c: Channel SIP/322-00000000 setting read format path: alaw -> alaw [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] channel.c: Channel SIP/611-00000001 setting write format path: alaw -> alaw [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] channel.c: Channel SIP/611-00000001 setting read format path: alaw -> alaw [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] channel.c: Channel SIP/322-00000000 setting write format path: alaw -> alaw [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] channel.c: Channel SIP/322-00000000 setting write format path: alaw -> alaw [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: 0x7f7fdc005108(SIP/322-00000000) is joining simple_bridge technology [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] channel.c: Channel SIP/322-00000000 setting read format path: alaw -> alaw [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] channel.c: Channel SIP/611-00000001 setting write format path: alaw -> alaw [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] channel.c: Channel SIP/611-00000001 setting read format path: alaw -> alaw [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] channel.c: Channel SIP/322-00000000 setting write format path: alaw -> alaw [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] channel.c: Channel SIP/322-00000000 setting write format path: alaw -> alaw [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: calling simple_bridge technology start [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4: calling native_rtp technology destructor [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] dahdi/bridge_native_dahdi.c: Channel 'SIP/611-00000001' is not DAHDI. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] dahdi/bridge_native_dahdi.c: Bridge bridge_5b699064c1cc4: Cannot use native DAHDI. Channel 'SIP/611-00000001' not compatible. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Checking compatability for channels 'SIP/611-00000001' and 'SIP/322-00000000' [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4' can not use native RTP bridge as channel 'SIP/322-00000000' has features which prevent it [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Chose bridge technology simple_bridge [Aug 7 14:28:33.873] DEBUG[19663][C-00000001] bridge.c: Bridge bridge_5b699064c1cc4 is already using the new technology. [Aug 7 14:28:33.874] DEBUG[18794] threadpool.c: Increasing threadpool stasis-core's size by 1 [Aug 7 14:28:33.874] DEBUG[19673] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 490 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 490 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 497 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 497 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 537 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 537 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 490 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 490 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 497 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 497 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 537 [Aug 7 14:28:33.874] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 537 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 510 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 510 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 550 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 550 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 510 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 510 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 550 [Aug 7 14:28:33.874] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 550 [Aug 7 14:28:33.875] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 457 [Aug 7 14:28:33.875] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 457 [Aug 7 14:28:33.875] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 444 [Aug 7 14:28:33.875] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 444 [Aug 7 14:28:33.875] DEBUG[19674] chan_sip.c: ** Our capability: (alaw) Video flag: True Text flag: True [Aug 7 14:28:33.875] DEBUG[19674] chan_sip.c: ** Our prefcodec: (slin) [Aug 7 14:28:33.875] DEBUG[19674] chan_sip.c: -- Done with adding codecs to SDP [Aug 7 14:28:33.875] DEBUG[19674] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [Aug 7 14:28:33.875] DEBUG[19674] chan_sip.c: Initializing already initialized SIP dialog 1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060 (presumably reinvite) [Aug 7 14:28:33.875] DEBUG[19674] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:28:33.875] DEBUG[19674] dahdi/bridge_native_dahdi.c: Channel 'SIP/611-00000001' is not DAHDI. [Aug 7 14:28:33.875] DEBUG[19674] dahdi/bridge_native_dahdi.c: Bridge bridge_5b699064c1cc4: Cannot use native DAHDI. Channel 'SIP/611-00000001' not compatible. [Aug 7 14:28:33.875] DEBUG[19674] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:28:33.875] DEBUG[19674] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:28:33.875] DEBUG[19674] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4'. Checking compatability for channels 'SIP/611-00000001' and 'SIP/322-00000000' [Aug 7 14:28:33.875] DEBUG[19674] bridge_native_rtp.c: Bridge 'bridge_5b699064c1cc4' can not use native RTP bridge as channel 'SIP/322-00000000' has features which prevent it [Aug 7 14:28:33.875] DEBUG[19674] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 7 14:28:33.875] DEBUG[19674] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:28:33.876] DEBUG[19674] bridge.c: Chose bridge technology simple_bridge [Aug 7 14:28:33.876] DEBUG[19674] bridge.c: Bridge bridge_5b699064c1cc4 is already using the new technology. [Aug 7 14:28:33.876] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 501 [Aug 7 14:28:33.876] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 501 [Aug 7 14:28:33.876] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 488 [Aug 7 14:28:33.876] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 488 [Aug 7 14:28:33.876] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 515 [Aug 7 14:28:33.876] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 515 [Aug 7 14:28:33.876] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 502 [Aug 7 14:28:33.876] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 502 [Aug 7 14:28:33.876] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 510 [Aug 7 14:28:33.876] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 510 [Aug 7 14:28:33.876] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 497 [Aug 7 14:28:33.876] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 497 [Aug 7 14:28:33.877] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 550 [Aug 7 14:28:33.877] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 550 [Aug 7 14:28:33.877] DEBUG[19013] res_http_websocket.c: Writing websocket string of length 537 [Aug 7 14:28:33.877] DEBUG[19013] res_http_websocket.c: Writing websocket text frame, length 537 [Aug 7 14:28:33.877] DEBUG[19674] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. Qualifying new stream. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: = Looking for Call ID: 1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060 (Checking To) --From tag as542355a5 --To-tag YgfK1gM0czBUUeEO341.HVXrZoRK-9WY [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Acked pending invite 103 [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Stopping retransmission on '1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060' of Request 103: Match Found [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: SIP response 200 to RE-invite on outgoing call 1ff3c6e728609d2842dd9bed0f167de1@95.80.200.221:5060 [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing session-level SDP o=- 3742633700 3742633702 IN IP4 10.255.255.167... OK. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing session-level SDP s=pjmedia... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing session-level SDP b=AS:117... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing session-level SDP a=X-nat:0... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.880] DEBUG[18944] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f7f8e6ced00 [Aug 7 14:28:33.880] DEBUG[18944] netsock2.c: Splitting '10.255.255.167' into... [Aug 7 14:28:33.880] DEBUG[18944] netsock2.c: ...host '10.255.255.167' and port ''. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP c=IN IP4 10.255.255.167... OK. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP b=TIAS:96000... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP a=rtcp:4007 IN IP4 10.255.255.167... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED OR FAILED. [Aug 7 14:28:33.880] DEBUG[18944] acl.c: For destination '10.255.255.167', our source address is '95.80.200.221'. [Aug 7 14:28:33.880] DEBUG[18944] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f7fd8009f68' [Aug 7 14:28:33.880] VERBOSE[18944] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Strict RTP learning after remote address set to: 10.255.255.167:4006 [Aug 7 14:28:33.880] DEBUG[18944] rtp_engine.c: Copying tx payload mapping 8 (0x7f7fb001fad0) from 0x7f7f8e6ced00 to 0x7f7fd800a140 [Aug 7 14:28:33.880] DEBUG[18944] rtp_engine.c: Copying tx payload mapping 101 (0x7f7fb00114c0) from 0x7f7f8e6ced00 to 0x7f7fd800a140 [Aug 7 14:28:33.880] DEBUG[18944] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f7fd8009f68' [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: We're settling with these formats: (alaw) [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: We have an owner, now see if we need to change this call [Aug 7 14:28:33.880] DEBUG[18944] channel.c: Channel SIP/611-00000001 setting read format path: alaw -> alaw [Aug 7 14:28:33.880] DEBUG[18944] channel.c: Channel SIP/611-00000001 setting write format path: alaw -> alaw [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Updating call counter for outgoing call [Aug 7 14:28:33.880] DEBUG[18944] chan_sip.c: Trying to put 'ACK sip:611' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:28:33.880] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:28:33.880] DEBUG[18805] chan_sip.c: Checking device state for peer 611 [Aug 7 14:28:33.880] DEBUG[18805] devicestate.c: Changing state for SIP/611 - state 2 (In use) [Aug 7 14:28:33.892] DEBUG[19663][C-00000001] media_cache.c: Failed to obtain media at '/var/lib/asterisk/mohmp3//TristeAlegriaPromo' [Aug 7 14:28:33.892] DEBUG[19663][C-00000001] media_cache.c: Failed to obtain media at '/var/lib/asterisk/mohmp3//TristeAlegriaPromo' [Aug 7 14:28:33.892] DEBUG[19663][C-00000001] channel.c: Channel SIP/322-00000000 setting write format path: slin -> alaw [Aug 7 14:28:33.892] DEBUG[19663][C-00000001] res_musiconhold.c: SIP/322-00000000 Opened file 0 '/var/lib/asterisk/mohmp3//TristeAlegriaPromo' [Aug 7 14:28:33.892] DEBUG[19674] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. Qualifying new stream. [Aug 7 14:28:33.896] DEBUG[18944] chan_sip.c: = Looking for Call ID: 3890068728@10.255.255.157 (Checking To) --From tag as7131796c --To-tag 4052487425 [Aug 7 14:28:33.896] DEBUG[18944][C-00000001] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '3890068728@10.255.255.157' Request 102: Found [Aug 7 14:28:33.896] DEBUG[18944][C-00000001] chan_sip.c: SIP response 100 to RE-invite on outgoing call 3890068728@10.255.255.157 [Aug 7 14:28:33.904] VERBOSE[19674] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Strict RTP qualifying stream type: audio [Aug 7 14:28:33.904] DEBUG[19674] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. Will switch to it in 3 packets. [Aug 7 14:28:33.926] DEBUG[19674] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. Will switch to it in 2 packets. [Aug 7 14:28:33.950] DEBUG[19674] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Received RTP packet from 172.21.254.254:4006, dropping due to strict RTP protection. Will switch to it in 1 packets. [Aug 7 14:28:33.974] VERBOSE[19674] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Strict RTP switching source address to 172.21.254.254:4006 [Aug 7 14:28:33.974] DEBUG[19674] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:28:33.974] DEBUG[19674] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f7fd8009f68' [Aug 7 14:28:34.009] DEBUG[18944] chan_sip.c: = Looking for Call ID: 3890068728@10.255.255.157 (Checking To) --From tag as7131796c --To-tag 4052487425 [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Acked pending invite 102 [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Stopping retransmission on '3890068728@10.255.255.157' of Request 102: Match Found [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: SIP response 200 to RE-invite on outgoing call 3890068728@10.255.255.157 [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Processing session-level SDP o=- 20027 20028 IN IP4 10.255.255.157... OK. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Processing session-level SDP s=SDP data... UNSUPPORTED OR FAILED. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] netsock2.c: Splitting '10.255.255.157' into... [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] netsock2.c: ...host '10.255.255.157' and port ''. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Processing session-level SDP c=IN IP4 10.255.255.157... OK. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f7f8e6ced00 [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Setting framing to 20 [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] acl.c: For destination '10.255.255.157', our source address is '95.80.200.221'. [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f7fb00017a8' [Aug 7 14:28:34.009] VERBOSE[18944][C-00000001] res_rtp_asterisk.c: 0x7f7fb000c830 -- Strict RTP learning after remote address set to: 10.255.255.157:11790 [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] rtp_engine.c: Copying tx payload mapping 8 (0x7f7fb0000e70) from 0x7f7f8e6ced00 to 0x7f7fb0001980 [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] rtp_engine.c: Copying tx payload mapping 101 (0x7f7fb0006350) from 0x7f7f8e6ced00 to 0x7f7fb0001980 [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f7fb00017a8' [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: We're settling with these formats: (alaw) [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: We have an owner, now see if we need to change this call [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] channel.c: Channel SIP/322-00000000 setting read format path: alaw -> alaw [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Updating call counter for incoming call [Aug 7 14:28:34.009] DEBUG[18944][C-00000001] chan_sip.c: Trying to put 'ACK sip:322' onto UDP socket destined for 172.21.254.254:5063 [Aug 7 14:28:34.009] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - 322 [Aug 7 14:28:34.009] DEBUG[18805] chan_sip.c: Checking device state for peer 322 [Aug 7 14:28:34.009] DEBUG[18805] devicestate.c: Changing state for SIP/322 - state 2 (In use) [Aug 7 14:28:34.012] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Ooh, format changed from none to alaw [Aug 7 14:28:34.018] DEBUG[19663][C-00000001] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:28:34.018] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f7fb00017a8' [Aug 7 14:28:36.659] DEBUG[18946] chan_iax2.c: ip callno count decremented to 0 for 127.0.0.1 [Aug 7 14:28:36.660] DEBUG[18958] chan_iax2.c: ip callno count incremented to 1 for 127.0.0.1 [Aug 7 14:28:36.660] DEBUG[18950] chan_iax2.c: schedule decrement of callno used for 127.0.0.1 in 60 seconds [Aug 7 14:28:36.660] DEBUG[18950] chan_iax2.c: Peer loopback: got pong, lastms 3, historicms 3, maxms 2000 [Aug 7 14:28:37.212] DEBUG[19674] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4007 [Aug 7 14:28:38.463] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:28:38.885] VERBOSE[19674] res_rtp_asterisk.c: 0x7f7fd800aee0 -- Strict RTP learning complete - Locking on source address 172.21.254.254:4006 [Aug 7 14:28:39.019] VERBOSE[19663][C-00000001] res_rtp_asterisk.c: 0x7f7fb000c830 -- Strict RTP learning complete - Locking on source address 172.21.254.254:11790 [Aug 7 14:28:40.974] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11791 [Aug 7 14:28:40.991] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:28:42.031] DEBUG[19674] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4007 [Aug 7 14:28:42.838] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 43ba26ef203e44d21631d7b10c8d19c0@95.80.200.221:5060 - OPTIONS (No RTP) [Aug 7 14:28:42.838] DEBUG[18944] acl.c: For destination 'test.test.com', our source address is '95.80.200.221'. [Aug 7 14:28:42.838] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:42.838] DEBUG[18944] chan_sip.c: SIP call-id changed from '43ba26ef203e44d21631d7b10c8d19c0@95.80.200.221:5060' to '2792682f3087e78d2e71faff535ddced@95.80.200.221:5060' [Aug 7 14:28:42.838] DEBUG[18944] chan_sip.c: Initializing initreq for method OPTIONS - callid 2792682f3087e78d2e71faff535ddced@95.80.200.221:5060 [Aug 7 14:28:42.838] DEBUG[18944] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for test.test.com:5060 [Aug 7 14:28:42.839] DEBUG[18944] chan_sip.c: = Looking for Call ID: 2792682f3087e78d2e71faff535ddced@95.80.200.221:5060 (Checking To) --From tag as3e7ed35d --To-tag as27068597 [Aug 7 14:28:42.839] DEBUG[18944] chan_sip.c: Stopping retransmission on '2792682f3087e78d2e71faff535ddced@95.80.200.221:5060' of Request 102: Match Found [Aug 7 14:28:42.839] DEBUG[18944] chan_sip.c: Destroying SIP dialog 2792682f3087e78d2e71faff535ddced@95.80.200.221:5060 [Aug 7 14:28:43.463] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:28:43.884] DEBUG[19673] iostream.c: TCP timeout reading data [Aug 7 14:28:43.884] DEBUG[19673] http.c: HTTP closing session. Top level [Aug 7 14:28:45.974] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11791 [Aug 7 14:28:45.991] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:28:46.850] DEBUG[19674] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4007 [Aug 7 14:28:48.463] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:28:50.973] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11791 [Aug 7 14:28:50.991] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:28:51.278] DEBUG[18944] chan_sip.c: = Looking for Call ID: 833107005@192.168.10.125 (Checking From) --From tag 841422564 --To-tag [Aug 7 14:28:51.279] DEBUG[18944] acl.c: For destination '212.24.153.186', our source address is '95.80.200.221'. [Aug 7 14:28:51.279] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:51.279] DEBUG[18944] netsock2.c: Splitting '192.168.10.125:5063' into... [Aug 7 14:28:51.279] DEBUG[18944] netsock2.c: ...host '192.168.10.125' and port '5063'. [Aug 7 14:28:51.279] DEBUG[18944] chan_sip.c: NAT detected for 192.168.10.125 / 212.24.153.186 [Aug 7 14:28:51.279] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 833107005@192.168.10.125 - REGISTER (No RTP) [Aug 7 14:28:51.279] DEBUG[18944] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Aug 7 14:28:51.279] DEBUG[18944] netsock2.c: Splitting '192.168.10.125:5063' into... [Aug 7 14:28:51.279] DEBUG[18944] netsock2.c: ...host '192.168.10.125' and port '5063'. [Aug 7 14:28:51.279] DEBUG[18944] chan_sip.c: NAT detected for 192.168.10.125 / 212.24.153.186 [Aug 7 14:28:51.279] DEBUG[18944] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:28:51.279] DEBUG[18944] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:28:51.279] DEBUG[18944] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 212.24.153.186:5063 [Aug 7 14:28:51.424] DEBUG[18944] chan_sip.c: = Looking for Call ID: 833107005@192.168.10.125 (Checking From) --From tag 841422564 --To-tag [Aug 7 14:28:51.424] DEBUG[18944] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Aug 7 14:28:51.424] DEBUG[18944] netsock2.c: Splitting '192.168.10.125:5063' into... [Aug 7 14:28:51.424] DEBUG[18944] netsock2.c: ...host '192.168.10.125' and port '5063'. [Aug 7 14:28:51.424] DEBUG[18944] chan_sip.c: NAT detected for 192.168.10.125 / 212.24.153.186 [Aug 7 14:28:51.424] DEBUG[18944] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:28:51.424] DEBUG[18944] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:28:51.424] DEBUG[18944] chan_sip.c: Store REGISTER's src-IP:port for call routing. [Aug 7 14:28:51.424] DEBUG[18944] chan_sip.c: build_path: do not use Path headers [Aug 7 14:28:51.425] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 67fd5f9c6397c27a5d84b18e08ebfba7@95.80.200.221:5060 - OPTIONS (No RTP) [Aug 7 14:28:51.425] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 227 [Aug 7 14:28:51.425] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 227 [Aug 7 14:28:51.425] DEBUG[18944] acl.c: For destination '212.24.153.186', our source address is '95.80.200.221'. [Aug 7 14:28:51.425] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:51.425] DEBUG[18944] chan_sip.c: SIP call-id changed from '67fd5f9c6397c27a5d84b18e08ebfba7@95.80.200.221:5060' to '418fafb25dafe4732bccf04a529ac4d7@95.80.200.221:5060' [Aug 7 14:28:51.425] DEBUG[18989] res_http_websocket.c: Writing websocket string of length 292 [Aug 7 14:28:51.425] DEBUG[18989] res_http_websocket.c: Writing websocket text frame, length 292 [Aug 7 14:28:51.425] DEBUG[18944] chan_sip.c: Initializing initreq for method OPTIONS - callid 418fafb25dafe4732bccf04a529ac4d7@95.80.200.221:5060 [Aug 7 14:28:51.425] DEBUG[18944] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 212.24.153.186:5063 [Aug 7 14:28:51.425] VERBOSE[18944] chan_sip.c: Saved useragent "Yealink SIP-T28P fw2.72.9.20 hw1.0.0.4 00:15:65:12:15:a3" for peer well [Aug 7 14:28:51.425] DEBUG[18944] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 212.24.153.186:5063 [Aug 7 14:28:51.425] DEBUG[18805] devicestate.c: No provider found, checking channel drivers for SIP - well [Aug 7 14:28:51.425] DEBUG[18805] chan_sip.c: Checking device state for peer well [Aug 7 14:28:51.425] DEBUG[18805] devicestate.c: Changing state for SIP/well - state 1 (Not in use) [Aug 7 14:28:51.567] DEBUG[18944] chan_sip.c: = Looking for Call ID: 418fafb25dafe4732bccf04a529ac4d7@95.80.200.221:5060 (Checking To) --From tag as065e5cc3 --To-tag 1866403692 [Aug 7 14:28:51.567] DEBUG[18944] chan_sip.c: Stopping retransmission on '418fafb25dafe4732bccf04a529ac4d7@95.80.200.221:5060' of Request 102: Match Found [Aug 7 14:28:51.567] DEBUG[18944] chan_sip.c: Destroying SIP dialog 418fafb25dafe4732bccf04a529ac4d7@95.80.200.221:5060 [Aug 7 14:28:51.669] DEBUG[19674] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4007 [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 35ad0ac7670edfa36bc4b8365357dfbe@95.80.200.221:5060 - OPTIONS (No RTP) [Aug 7 14:28:52.848] DEBUG[18944] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: SIP call-id changed from '35ad0ac7670edfa36bc4b8365357dfbe@95.80.200.221:5060' to '5543ea3e3cdc15e64b267ed80f5ff8da@95.80.200.221:5060' [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Initializing initreq for method OPTIONS - callid 5543ea3e3cdc15e64b267ed80f5ff8da@95.80.200.221:5060 [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 36c0ab9e60a9842171dd435706937ec0@95.80.200.221:5060 - OPTIONS (No RTP) [Aug 7 14:28:52.848] DEBUG[18944] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: SIP call-id changed from '36c0ab9e60a9842171dd435706937ec0@95.80.200.221:5060' to '5ac3b9882508c03a4361702f178aa6ce@95.80.200.221:5060' [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Initializing initreq for method OPTIONS - callid 5ac3b9882508c03a4361702f178aa6ce@95.80.200.221:5060 [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 1db9943a2f3b45377b1826462bacf5e5@95.80.200.221:5060 - OPTIONS (No RTP) [Aug 7 14:28:52.848] DEBUG[18944] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: SIP call-id changed from '1db9943a2f3b45377b1826462bacf5e5@95.80.200.221:5060' to '4d2613d34cfe289047f2438b3514837f@95.80.200.221:5060' [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Initializing initreq for method OPTIONS - callid 4d2613d34cfe289047f2438b3514837f@95.80.200.221:5060 [Aug 7 14:28:52.848] DEBUG[18944] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:28:52.980] DEBUG[18944] chan_sip.c: = Looking for Call ID: 5543ea3e3cdc15e64b267ed80f5ff8da@95.80.200.221:5060 (Checking To) --From tag as32d4b8c1 --To-tag z9hG4bK77029a40 [Aug 7 14:28:52.980] DEBUG[18944] chan_sip.c: Stopping retransmission on '5543ea3e3cdc15e64b267ed80f5ff8da@95.80.200.221:5060' of Request 102: Match Found [Aug 7 14:28:52.980] DEBUG[18944] chan_sip.c: Destroying SIP dialog 5543ea3e3cdc15e64b267ed80f5ff8da@95.80.200.221:5060 [Aug 7 14:28:52.980] DEBUG[18944] chan_sip.c: = Looking for Call ID: 5ac3b9882508c03a4361702f178aa6ce@95.80.200.221:5060 (Checking To) --From tag as485b529f --To-tag z9hG4bK7c54a5b0 [Aug 7 14:28:52.980] DEBUG[18944] chan_sip.c: Stopping retransmission on '5ac3b9882508c03a4361702f178aa6ce@95.80.200.221:5060' of Request 102: Match Found [Aug 7 14:28:52.980] DEBUG[18944] chan_sip.c: Destroying SIP dialog 5ac3b9882508c03a4361702f178aa6ce@95.80.200.221:5060 [Aug 7 14:28:52.981] DEBUG[18944] chan_sip.c: = Looking for Call ID: 4d2613d34cfe289047f2438b3514837f@95.80.200.221:5060 (Checking To) --From tag as0e41ae9c --To-tag z9hG4bK4ac8a45e [Aug 7 14:28:52.981] DEBUG[18944] chan_sip.c: Stopping retransmission on '4d2613d34cfe289047f2438b3514837f@95.80.200.221:5060' of Request 102: Match Found [Aug 7 14:28:52.981] DEBUG[18944] chan_sip.c: Destroying SIP dialog 4d2613d34cfe289047f2438b3514837f@95.80.200.221:5060 [Aug 7 14:28:53.037] DEBUG[18944] chan_sip.c: Allocating new SIP dialog for 2a1d4ba67b7a080d65e523246aea89ad@95.80.200.221:5060 - OPTIONS (No RTP) [Aug 7 14:28:53.037] DEBUG[18944] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:28:53.037] DEBUG[18944] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:28:53.037] DEBUG[18944] chan_sip.c: SIP call-id changed from '2a1d4ba67b7a080d65e523246aea89ad@95.80.200.221:5060' to '7d62519266bf4c52462673b171b4308e@95.80.200.221:5060' [Aug 7 14:28:53.037] DEBUG[18944] chan_sip.c: Initializing initreq for method OPTIONS - callid 7d62519266bf4c52462673b171b4308e@95.80.200.221:5060 [Aug 7 14:28:53.037] DEBUG[18944] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 172.21.254.254:5063 [Aug 7 14:28:53.118] DEBUG[18944] chan_sip.c: = Looking for Call ID: 7d62519266bf4c52462673b171b4308e@95.80.200.221:5060 (Checking To) --From tag as7b06d5fd --To-tag 1000838194 [Aug 7 14:28:53.118] DEBUG[18944] chan_sip.c: Stopping retransmission on '7d62519266bf4c52462673b171b4308e@95.80.200.221:5060' of Request 102: Match Found [Aug 7 14:28:53.118] DEBUG[18944] chan_sip.c: Destroying SIP dialog 7d62519266bf4c52462673b171b4308e@95.80.200.221:5060 [Aug 7 14:28:53.464] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:28:53.874] DEBUG[19675] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 7 14:28:53.874] DEBUG[19676] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 7 14:28:53.874] DEBUG[18794] threadpool.c: Destroying worker thread 19 [Aug 7 14:28:53.874] DEBUG[18794] threadpool.c: Destroying worker thread 20 [Aug 7 14:28:55.974] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11791 [Aug 7 14:28:55.991] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:28:56.488] DEBUG[19674] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4007 [Aug 7 14:28:56.498] DEBUG[18944] chan_sip.c: Auto destroying SIP dialog '1998117674@192.168.10.120' [Aug 7 14:28:56.498] DEBUG[18944] chan_sip.c: Destroying SIP dialog 1998117674@192.168.10.120 [Aug 7 14:28:58.464] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:28:59.995] DEBUG[19701] http.c: HTTP opening session. Top level [Aug 7 14:28:59.995] DEBUG[19701] http.c: HTTP Request URI is /ari/channels/1533644900.1/ring [Aug 7 14:28:59.995] DEBUG[19701] http.c: match request [ari/channels/1533644900.1/ring] with handler [httpstatus] len 10 [Aug 7 14:28:59.995] DEBUG[19701] http.c: match request [ari/channels/1533644900.1/ring] with handler [static] len 6 [Aug 7 14:28:59.995] DEBUG[19701] http.c: match request [ari/channels/1533644900.1/ring] with handler [ari] len 3 [Aug 7 14:28:59.995] DEBUG[19701] http.c: Match made with [ari] [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Finding handler for channels [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Checking playbacks [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Checking channels [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Got it! [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Finding handler for 1533644900.1 [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Checking create [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Checking channelId [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Got it! [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Finding handler for ring [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Checking continue [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Checking redirect [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Checking answer [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Checking ring [Aug 7 14:28:59.995] DEBUG[19701] res_ari.c: Got it! [Aug 7 14:28:59.995] DEBUG[19664] channel.c: Driver for channel 'SIP/611-00000001' does not support indication 3, emulating it [Aug 7 14:28:59.995] DEBUG[19664] channel.c: Channel SIP/611-00000001 setting write format path: slin -> alaw [Aug 7 14:28:59.995] DEBUG[19664] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Aug 7 14:28:59.995] DEBUG[19701] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:28:59.996] DEBUG[19701] http.c: HTTP closing session. Top level [Aug 7 14:29:00.015] DEBUG[19674] res_rtp_asterisk.c: Ooh, format changed from none to alaw [Aug 7 14:29:00.200] DEBUG[19674] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4007 [Aug 7 14:29:00.974] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11791 [Aug 7 14:29:00.974] DEBUG[19674] channel.c: Channel SIP/611-00000001 setting write format path: alaw -> alaw [Aug 7 14:29:00.974] DEBUG[19674] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Aug 7 14:29:00.991] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:29:01.304] DEBUG[19674] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4007 [Aug 7 14:29:03.464] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:29:05.868] DEBUG[18944] chan_sip.c: Auto destroying SIP dialog '34023d0225aa15730ebd5a6b1d40ef05@test.test.com:5060' [Aug 7 14:29:05.868] DEBUG[18944] chan_sip.c: Destroying SIP dialog 34023d0225aa15730ebd5a6b1d40ef05@test.test.com:5060 [Aug 7 14:29:05.974] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11791 [Aug 7 14:29:05.991] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:29:06.135] DEBUG[19674] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4007 [Aug 7 14:29:08.464] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:29:10.953] DEBUG[19674] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4007 [Aug 7 14:29:10.974] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11791 [Aug 7 14:29:10.991] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791 [Aug 7 14:29:11.425] DEBUG[19661] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 7 14:29:11.425] DEBUG[18794] threadpool.c: Destroying worker thread 18 [Aug 7 14:29:13.464] DEBUG[19663][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11791