[Aug 7 14:46:00.599] DEBUG[16787] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 7 14:46:00.599] DEBUG[16786] threadpool.c: Destroying worker thread 0 [Aug 7 14:46:00.905] DEBUG[16936] chan_sip.c: = Looking for Call ID: 1808813369@10.255.255.157 (Checking From) --From tag 3714664092 --To-tag [Aug 7 14:46:00.905] DEBUG[16936] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:46:00.905] DEBUG[16936] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:46:00.905] DEBUG[16936] netsock2.c: Splitting '10.255.255.157:5063' into... [Aug 7 14:46:00.905] DEBUG[16936] netsock2.c: ...host '10.255.255.157' and port '5063'. [Aug 7 14:46:00.905] DEBUG[16936] chan_sip.c: NAT detected for 10.255.255.157 / 172.21.254.254 [Aug 7 14:46:00.905] DEBUG[16936] chan_sip.c: Allocating new SIP dialog for 1808813369@10.255.255.157 - INVITE (No RTP) [Aug 7 14:46:00.905] DEBUG[16936][C-00000001] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 7 14:46:00.905] DEBUG[16936][C-00000001] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces" [Aug 7 14:46:00.905] DEBUG[16936][C-00000001] sip/reqresp_parser.c: Found SIP option: -replaces- [Aug 7 14:46:00.905] DEBUG[16936][C-00000001] sip/reqresp_parser.c: Matched SIP option: replaces [Aug 7 14:46:00.905] DEBUG[16936][C-00000001] netsock2.c: Splitting '10.255.255.157:5063' into... [Aug 7 14:46:00.905] DEBUG[16936][C-00000001] netsock2.c: ...host '10.255.255.157' and port '5063'. [Aug 7 14:46:00.905] DEBUG[16936][C-00000001] chan_sip.c: NAT detected for 10.255.255.157 / 172.21.254.254 [Aug 7 14:46:00.905] DEBUG[16936][C-00000001] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:46:00.905] DEBUG[16936][C-00000001] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:46:00.905] DEBUG[16936][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:46:00.923] DEBUG[16936] chan_sip.c: = Looking for Call ID: 1808813369@10.255.255.157 (Checking From) --From tag 3714664092 --To-tag as0902e832 [Aug 7 14:46:00.923] DEBUG[16936][C-00000001] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 7 14:46:00.923] DEBUG[16936][C-00000001] chan_sip.c: Stopping retransmission on '1808813369@10.255.255.157' of Response 1: Match Found [Aug 7 14:46:01.003] DEBUG[16936] chan_sip.c: = Looking for Call ID: 1808813369@10.255.255.157 (Checking From) --From tag 3714664092 --To-tag [Aug 7 14:46:01.003] DEBUG[16936] netsock2.c: Splitting 'stasis.daktela.com:5060' into... [Aug 7 14:46:01.003] DEBUG[16936] netsock2.c: ...host 'stasis.daktela.com' and port '5060'. [Aug 7 14:46:01.003] DEBUG[16936] netsock2.c: Splitting 'stasis.daktela.com:5060' into... [Aug 7 14:46:01.003] DEBUG[16936] netsock2.c: ...host 'stasis.daktela.com' and port '5060'. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: Splitting '10.255.255.157:5063' into... [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: ...host '10.255.255.157' and port '5063'. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: NAT detected for 10.255.255.157 / 172.21.254.254 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fbba0006498' [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] res_rtp_asterisk.c: Allocated port 15088 for RTP instance '0x7fbba0006498' [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: RTP instance '0x7fbba0006498' is setup and ready to go [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: Splitting 'stasis' into... [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: ...host 'stasis' and port ''. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fbba0006498' [Aug 7 14:46:01.003] VERBOSE[16936][C-00000001] netsock2.c: Using SIP RTP CoS mark 5 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Setting NAT on RTP to On [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing session-level SDP o=- 20030 20030 IN IP4 10.255.255.157... OK. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing session-level SDP s=SDP data... UNSUPPORTED OR FAILED. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: Splitting '10.255.255.157' into... [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: ...host '10.255.255.157' and port ''. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing session-level SDP c=IN IP4 10.255.255.157... OK. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7fbb80c3fa20 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7fbb80c3fa20 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Setting tx payload type 18 based on m type on 0x7fbb80c3fa20 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Setting tx payload type 9 based on m type on 0x7fbb80c3fa20 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... OK. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Setting framing to 20 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 0 (0x7fbba0003d90) from 0x7fbb80c3fa20 to 0x7fbb80c3fa20 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 8 (0x7fbba00189c0) from 0x7fbb80c3fa20 to 0x7fbb80c3fa20 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 9 (0x7fbba0018a40) from 0x7fbb80c3fa20 to 0x7fbb80c3fa20 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 18 (0x7fbba0017990) from 0x7fbb80c3fa20 to 0x7fbb80c3fa20 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Crossover copying tx to rx payload mapping 101 (0x7fbba0017a70) from 0x7fbb80c3fa20 to 0x7fbb80c3fa20 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] acl.c: For destination '10.255.255.157', our source address is '95.80.200.221'. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fbba0006498' [Aug 7 14:46:01.003] VERBOSE[16936][C-00000001] res_rtp_asterisk.c: 0x7fbba0014640 -- Strict RTP learning after remote address set to: 10.255.255.157:11796 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Copying rx payload mapping 0 (0x7fbba0003d90) from 0x7fbb80c3fa20 to 0x7fbba0006670 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Copying rx payload mapping 8 (0x7fbba00189c0) from 0x7fbb80c3fa20 to 0x7fbba0006670 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Copying rx payload mapping 9 (0x7fbba0018a40) from 0x7fbb80c3fa20 to 0x7fbba0006670 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Copying rx payload mapping 18 (0x7fbba0017990) from 0x7fbb80c3fa20 to 0x7fbba0006670 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Copying rx payload mapping 101 (0x7fbba0017a70) from 0x7fbb80c3fa20 to 0x7fbba0006670 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Copying tx payload mapping 0 (0x7fbba0003d90) from 0x7fbb80c3fa20 to 0x7fbba0006670 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Copying tx payload mapping 8 (0x7fbba00189c0) from 0x7fbb80c3fa20 to 0x7fbba0006670 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Copying tx payload mapping 9 (0x7fbba0018a40) from 0x7fbb80c3fa20 to 0x7fbba0006670 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Copying tx payload mapping 18 (0x7fbba0017990) from 0x7fbb80c3fa20 to 0x7fbba0006670 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] rtp_engine.c: Copying tx payload mapping 101 (0x7fbba0017a70) from 0x7fbb80c3fa20 to 0x7fbba0006670 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fbba0006498' [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: We're settling with these formats: (alaw) [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Checking SIP call limits for device 322 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: Updating call counter for incoming call [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: Splitting 'stasis.daktela.com:5060' into... [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:46:01.003] DEBUG[16786] threadpool.c: Increasing threadpool stasis-core's size by 1 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] channel.c: Channel 0x7fbba00220a8 'SIP/322-00000000' allocated [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: *** Our native formats are (alaw) [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: *** Joint capabilities are (alaw) [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: *** Our capabilities are (alaw) [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: This channel will not be able to handle video. [Aug 7 14:46:01.003] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 240 [Aug 7 14:46:01.003] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 240 [Aug 7 14:46:01.003] DEBUG[16936][C-00000001] chan_sip.c: SIP/322-00000000: New call is still down.... Trying... [Aug 7 14:46:01.003] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 438 [Aug 7 14:46:01.003] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 438 [Aug 7 14:46:01.003] DEBUG[16936][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:46:01.004] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 495 [Aug 7 14:46:01.004] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 495 [Aug 7 14:46:01.004] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:46:01.004] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:46:01.004] DEBUG[16797] devicestate.c: No provider found, checking channel drivers for SIP - 322 [Aug 7 14:46:01.004] DEBUG[16797] chan_sip.c: Checking device state for peer 322 [Aug 7 14:46:01.004] DEBUG[16797] devicestate.c: Changing state for SIP/322 - state 2 (In use) [Aug 7 14:46:01.004] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 496 [Aug 7 14:46:01.004] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 496 [Aug 7 14:46:01.004] DEBUG[16797] devicestate.c: No provider found, checking channel drivers for SIP - 322 [Aug 7 14:46:01.004] DEBUG[16797] chan_sip.c: Checking device state for peer 322 [Aug 7 14:46:01.004] DEBUG[16797] devicestate.c: Changing state for SIP/322 - state 2 (In use) [Aug 7 14:46:01.004] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 442 [Aug 7 14:46:01.004] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 442 [Aug 7 14:46:01.004] DEBUG[16803] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock322 [Aug 7 14:46:01.004] DEBUG[16803] devicestate.c: Checking provider Custom with Custom [Aug 7 14:46:01.004] DEBUG[16803] db.c: Unable to find key 'StopCock322' in family 'CustomDevstate' [Aug 7 14:46:01.004] DEBUG[16803] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock322 [Aug 7 14:46:01.004] DEBUG[16803] devicestate.c: Checking provider Custom with Custom [Aug 7 14:46:01.004] DEBUG[16803] db.c: Unable to find key 'StopCock322' in family 'CustomDevstate' [Aug 7 14:46:01.004] DEBUG[17030][C-00000001] pbx.c: Launching 'Goto' [Aug 7 14:46:01.004] VERBOSE[17030][C-00000001] pbx.c: Executing [25@internal-device:1] Goto("SIP/322-00000000", "start") in new stack [Aug 7 14:46:01.004] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:46:01.004] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:46:01.005] VERBOSE[17030][C-00000001] pbx_builtins.c: Goto (internal-device,25,2) [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx_variables.c: Evaluating 'EXTEN' (from 'EXTEN}' len 5) [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx_variables.c: Result of 'EXTEN' is '25' [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] func_strings.c: String to search: (25) [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] func_strings.c: Characters to find: ( ) [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] func_strings.c: Character to replace with: () [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx_variables.c: Function REPLACE(EXTEN," ") result is '25' [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] func_strings.c: FUNCTION REGEX (^[0123456789*]+$)(25) [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx_variables.c: Function REGEX("^[0123456789*]+$" 25) result is '1' [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx_variables.c: Expression result is '1' [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx_variables.c: Evaluating 'EXTEN' (from 'EXTEN}' len 5) [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx_variables.c: Result of 'EXTEN' is '25' [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] func_strings.c: String to search: (25) [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] func_strings.c: Characters to find: ( ) [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] func_strings.c: Character to replace with: () [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx_variables.c: Function REPLACE(EXTEN," ") result is '25' [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx.c: Launching 'ExecIf' [Aug 7 14:46:01.005] VERBOSE[17030][C-00000001] pbx.c: Executing [25@internal-device:2] ExecIf("SIP/322-00000000", "1?Goto(25,detect)") in new stack [Aug 7 14:46:01.005] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:46:01.005] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:46:01.005] VERBOSE[17030][C-00000001] pbx_builtins.c: Goto (internal-device,25,4) [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx.c: Launching 'NoOp' [Aug 7 14:46:01.005] VERBOSE[17030][C-00000001] pbx.c: Executing [25@internal-device:4] NoOp("SIP/322-00000000", "") in new stack [Aug 7 14:46:01.005] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 484 [Aug 7 14:46:01.005] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 484 [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx_variables.c: Result of 'EXTEN' is '25' [Aug 7 14:46:01.005] DEBUG[17030][C-00000001] pbx_variables.c: Function DIALPLAN_EXISTS(internal-device-custom,25,1) result is '1' [Aug 7 14:46:01.006] DEBUG[17030][C-00000001] pbx_variables.c: Expression result is '1' [Aug 7 14:46:01.006] DEBUG[17030][C-00000001] pbx_variables.c: Result of 'EXTEN' is '25' [Aug 7 14:46:01.006] DEBUG[17030][C-00000001] pbx.c: Launching 'GotoIf' [Aug 7 14:46:01.006] VERBOSE[17030][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:46:01.006] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 515 [Aug 7 14:46:01.006] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 515 [Aug 7 14:46:01.006] VERBOSE[17030][C-00000001] pbx_builtins.c: Goto (internal-device-custom,25,1) [Aug 7 14:46:01.006] DEBUG[17030][C-00000001] pbx.c: Launching 'Stasis' [Aug 7 14:46:01.006] VERBOSE[17030][C-00000001] pbx.c: Executing [25@internal-device-custom:1] Stasis("SIP/322-00000000", "issues,start") in new stack [Aug 7 14:46:01.006] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 505 [Aug 7 14:46:01.006] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 505 [Aug 7 14:46:01.006] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 481 [Aug 7 14:46:01.006] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 481 [Aug 7 14:46:01.006] DEBUG[17030][C-00000001] stasis/app.c: Channel '1533645961.0' is 1 interested in issues [Aug 7 14:46:01.006] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 446 [Aug 7 14:46:01.006] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 446 [Aug 7 14:46:01.010] DEBUG[17031] http.c: HTTP opening session. Top level [Aug 7 14:46:01.010] DEBUG[17031] http.c: HTTP Request URI is /ari/channels/1533645961.0/answer [Aug 7 14:46:01.010] DEBUG[17031] http.c: match request [ari/channels/1533645961.0/answer] with handler [httpstatus] len 10 [Aug 7 14:46:01.010] DEBUG[17031] http.c: match request [ari/channels/1533645961.0/answer] with handler [static] len 6 [Aug 7 14:46:01.010] DEBUG[17031] http.c: match request [ari/channels/1533645961.0/answer] with handler [ari] len 3 [Aug 7 14:46:01.010] DEBUG[17031] http.c: Match made with [ari] [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Finding handler for channels [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Checking playbacks [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Checking channels [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Finding handler for 1533645961.0 [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Checking create [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Checking channelId [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Finding handler for answer [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Checking continue [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Checking redirect [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Checking answer [Aug 7 14:46:01.010] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:01.010] DEBUG[17031] res_stasis_answer.c: 1533645961.0: Sending answer command [Aug 7 14:46:01.207] DEBUG[17030][C-00000001] res_stasis_answer.c: 1533645961.0: Answering [Aug 7 14:46:01.207] DEBUG[17030][C-00000001] chan_sip.c: SIP answering channel: SIP/322-00000000 [Aug 7 14:46:01.207] DEBUG[17030][C-00000001] res_rtp_asterisk.c: Setting the marker bit due to a source update [Aug 7 14:46:01.207] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 434 [Aug 7 14:46:01.207] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 434 [Aug 7 14:46:01.207] DEBUG[17030][C-00000001] chan_sip.c: ** Our capability: (alaw) Video flag: True Text flag: True [Aug 7 14:46:01.207] DEBUG[17030][C-00000001] chan_sip.c: ** Our prefcodec: (nothing) [Aug 7 14:46:01.207] DEBUG[17030][C-00000001] chan_sip.c: -- Done with adding codecs to SDP [Aug 7 14:46:01.207] DEBUG[17030][C-00000001] chan_sip.c: Setting framing on incoming call: 20 [Aug 7 14:46:01.207] DEBUG[17030][C-00000001] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [Aug 7 14:46:01.207] DEBUG[17030][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:46:01.207] DEBUG[16797] devicestate.c: No provider found, checking channel drivers for SIP - 322 [Aug 7 14:46:01.207] DEBUG[16797] chan_sip.c: Checking device state for peer 322 [Aug 7 14:46:01.207] DEBUG[16797] devicestate.c: Changing state for SIP/322 - state 2 (In use) [Aug 7 14:46:01.207] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 447 [Aug 7 14:46:01.207] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 447 [Aug 7 14:46:01.209] DEBUG[17031] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:46:01.209] DEBUG[17031] http.c: HTTP Request URI is /ari/bridges [Aug 7 14:46:01.209] DEBUG[17031] http.c: match request [ari/bridges] with handler [httpstatus] len 10 [Aug 7 14:46:01.209] DEBUG[17031] http.c: match request [ari/bridges] with handler [static] len 6 [Aug 7 14:46:01.209] DEBUG[17031] http.c: match request [ari/bridges] with handler [ari] len 3 [Aug 7 14:46:01.209] DEBUG[17031] http.c: Match made with [ari] [Aug 7 14:46:01.209] DEBUG[17031] http.c: HTTP consuming request body [Aug 7 14:46:01.209] DEBUG[17031] res_ari.c: Finding handler for bridges [Aug 7 14:46:01.209] DEBUG[17031] res_ari.c: Checking playbacks [Aug 7 14:46:01.209] DEBUG[17031] res_ari.c: Checking channels [Aug 7 14:46:01.209] DEBUG[17031] res_ari.c: Checking asterisk [Aug 7 14:46:01.209] DEBUG[17031] res_ari.c: Checking events [Aug 7 14:46:01.209] DEBUG[17031] res_ari.c: Checking bridges [Aug 7 14:46:01.209] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:01.209] DEBUG[17031] dahdi/bridge_native_dahdi.c: Bridge bridge_5b69948932f3e: Cannot use native DAHDI. Must have two channels. [Aug 7 14:46:01.209] DEBUG[17031] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:46:01.209] DEBUG[17031] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:46:01.209] DEBUG[17031] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e' can not use native RTP bridge as two channels are required [Aug 7 14:46:01.209] DEBUG[17031] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 7 14:46:01.209] DEBUG[17031] bridge.c: Chose bridge technology simple_bridge [Aug 7 14:46:01.209] DEBUG[17031] bridge.c: Bridge bridge_5b69948932f3e: calling simple_bridge technology constructor [Aug 7 14:46:01.209] DEBUG[17031] bridge.c: Bridge bridge_5b69948932f3e: calling simple_bridge technology start [Aug 7 14:46:01.210] DEBUG[17031] http.c: HTTP keeping session open. status_code:200 [Aug 7 14:46:01.210] DEBUG[17031] http.c: HTTP Request URI is /ari/bridges/bridge_5b69948932f3e/addChannel [Aug 7 14:46:01.210] DEBUG[17031] http.c: match request [ari/bridges/bridge_5b69948932f3e/addChannel] with handler [httpstatus] len 10 [Aug 7 14:46:01.210] DEBUG[17031] http.c: match request [ari/bridges/bridge_5b69948932f3e/addChannel] with handler [static] len 6 [Aug 7 14:46:01.210] DEBUG[17031] http.c: match request [ari/bridges/bridge_5b69948932f3e/addChannel] with handler [ari] len 3 [Aug 7 14:46:01.210] DEBUG[17031] http.c: Match made with [ari] [Aug 7 14:46:01.210] DEBUG[17031] http.c: HTTP consuming request body [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Finding handler for bridges [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Checking playbacks [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Checking channels [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Checking asterisk [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Checking events [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Checking bridges [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Finding handler for bridge_5b69948932f3e [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Checking bridgeId [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Finding handler for addChannel [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Checking addChannel [Aug 7 14:46:01.210] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:01.210] DEBUG[17031] stasis/control.c: 1533645961.0: Sending channel add_to_bridge command [Aug 7 14:46:01.255] DEBUG[16936] chan_sip.c: = Looking for Call ID: 1808813369@10.255.255.157 (Checking From) --From tag 3714664092 --To-tag as61032b85 [Aug 7 14:46:01.255] DEBUG[16936][C-00000001] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 7 14:46:01.255] DEBUG[16936][C-00000001] chan_sip.c: Stopping retransmission on '1808813369@10.255.255.157' of Response 2: Match Found [Aug 7 14:46:01.397] DEBUG[16936] chan_sip.c: = Looking for Call ID: 1998117674@192.168.10.120 (Checking From) --From tag 1179217472 --To-tag [Aug 7 14:46:01.397] DEBUG[16936] acl.c: For destination '212.24.153.186', our source address is '95.80.200.221'. [Aug 7 14:46:01.397] DEBUG[16936] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:46:01.397] DEBUG[16936] netsock2.c: Splitting '192.168.10.120:5062' into... [Aug 7 14:46:01.397] DEBUG[16936] netsock2.c: ...host '192.168.10.120' and port '5062'. [Aug 7 14:46:01.397] DEBUG[16936] chan_sip.c: NAT detected for 192.168.10.120 / 212.24.153.186 [Aug 7 14:46:01.397] DEBUG[16936] chan_sip.c: Allocating new SIP dialog for 1998117674@192.168.10.120 - REGISTER (No RTP) [Aug 7 14:46:01.397] DEBUG[16936] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Aug 7 14:46:01.397] DEBUG[16936] netsock2.c: Splitting '192.168.10.120:5062' into... [Aug 7 14:46:01.397] DEBUG[16936] netsock2.c: ...host '192.168.10.120' and port '5062'. [Aug 7 14:46:01.397] DEBUG[16936] chan_sip.c: NAT detected for 192.168.10.120 / 212.24.153.186 [Aug 7 14:46:01.397] DEBUG[16936] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:46:01.397] DEBUG[16936] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:46:01.397] DEBUG[16936] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 212.24.153.186:5062 [Aug 7 14:46:01.407] DEBUG[17030][C-00000001] bridge_roles.c: Roles did not exist on channel SIP/322-00000000 [Aug 7 14:46:01.407] DEBUG[17030][C-00000001] stasis/control.c: 1533645961.0: Adding to bridge bridge_5b69948932f3e [Aug 7 14:46:01.407] DEBUG[17030][C-00000001] stasis/app.c: Bridge 'bridge_5b69948932f3e' is 1 interested in issues [Aug 7 14:46:01.407] DEBUG[17032][C-00000001] bridge_channel.c: Bridge bridge_5b69948932f3e: 0x7fbba0011288(SIP/322-00000000) is joining [Aug 7 14:46:01.407] DEBUG[17032][C-00000001] bridge_channel.c: Bridge bridge_5b69948932f3e: pushing 0x7fbba0011288(SIP/322-00000000) [Aug 7 14:46:01.407] VERBOSE[17032][C-00000001] bridge_channel.c: Channel SIP/322-00000000 joined 'simple_bridge' stasis-bridge [Aug 7 14:46:01.407] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 640 [Aug 7 14:46:01.407] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 640 [Aug 7 14:46:01.408] DEBUG[17032][C-00000001] dahdi/bridge_native_dahdi.c: Bridge bridge_5b69948932f3e: Cannot use native DAHDI. Must have two channels. [Aug 7 14:46:01.408] DEBUG[17032][C-00000001] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:46:01.408] DEBUG[17032][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:46:01.408] DEBUG[17032][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e' can not use native RTP bridge as two channels are required [Aug 7 14:46:01.408] DEBUG[17032][C-00000001] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 7 14:46:01.408] DEBUG[17032][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:46:01.408] DEBUG[17032][C-00000001] bridge.c: Chose bridge technology simple_bridge [Aug 7 14:46:01.408] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e is already using the new technology. [Aug 7 14:46:01.408] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: 0x7fbba0011288(SIP/322-00000000) is joining simple_bridge technology [Aug 7 14:46:01.408] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Changing ssrc from 283202980 to 677147936 due to a source change [Aug 7 14:46:01.408] DEBUG[17030][C-00000001] stasis/app.c: Bridge 'bridge_5b69948932f3e' is 2 interested in issues [Aug 7 14:46:01.408] DEBUG[17031] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:46:01.408] DEBUG[17031] http.c: HTTP Request URI is /ari/channels [Aug 7 14:46:01.408] DEBUG[17031] http.c: match request [ari/channels] with handler [httpstatus] len 10 [Aug 7 14:46:01.408] DEBUG[17031] http.c: match request [ari/channels] with handler [static] len 6 [Aug 7 14:46:01.408] DEBUG[17031] http.c: match request [ari/channels] with handler [ari] len 3 [Aug 7 14:46:01.408] DEBUG[17031] http.c: Match made with [ari] [Aug 7 14:46:01.408] DEBUG[17031] http.c: HTTP consuming request body [Aug 7 14:46:01.408] DEBUG[17031] res_ari.c: Finding handler for channels [Aug 7 14:46:01.408] DEBUG[17031] res_ari.c: Checking playbacks [Aug 7 14:46:01.408] DEBUG[17031] res_ari.c: Checking channels [Aug 7 14:46:01.408] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:01.408] DEBUG[17031] chan_sip.c: Asked to create a SIP channel with formats: (slin) [Aug 7 14:46:01.408] DEBUG[17031] chan_sip.c: Allocating new SIP dialog for 6f0af1894ba720bb187131860f7472b3@95.80.200.221:5060 - INVITE (No RTP) [Aug 7 14:46:01.409] DEBUG[17031] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fbba80076a8' [Aug 7 14:46:01.409] DEBUG[17031] res_rtp_asterisk.c: Allocated port 19524 for RTP instance '0x7fbba80076a8' [Aug 7 14:46:01.409] DEBUG[17031] rtp_engine.c: RTP instance '0x7fbba80076a8' is setup and ready to go [Aug 7 14:46:01.409] DEBUG[17031] netsock2.c: Splitting 'stasis' into... [Aug 7 14:46:01.409] DEBUG[17031] netsock2.c: ...host 'stasis' and port ''. [Aug 7 14:46:01.409] DEBUG[17031] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7fbba80076a8' [Aug 7 14:46:01.409] VERBOSE[17031] netsock2.c: Using SIP RTP CoS mark 5 [Aug 7 14:46:01.409] DEBUG[17031] chan_sip.c: Setting NAT on RTP to On [Aug 7 14:46:01.409] DEBUG[17031] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:46:01.409] DEBUG[17031] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:46:01.409] DEBUG[17031] chan_sip.c: Setting NAT on RTP to On [Aug 7 14:46:01.409] DEBUG[17031] chan_sip.c: SIP call-id changed from '6f0af1894ba720bb187131860f7472b3@95.80.200.221:5060' to '117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060' [Aug 7 14:46:01.409] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 240 [Aug 7 14:46:01.409] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 240 [Aug 7 14:46:01.409] DEBUG[17031] channel.c: Channel 0x7fbba800b868 'SIP/611-00000001' allocated [Aug 7 14:46:01.409] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 442 [Aug 7 14:46:01.409] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 442 [Aug 7 14:46:01.409] DEBUG[17031] chan_sip.c: *** Our native formats are (alaw) [Aug 7 14:46:01.409] DEBUG[17031] chan_sip.c: *** Joint capabilities are (nothing) [Aug 7 14:46:01.409] DEBUG[17031] chan_sip.c: *** Our capabilities are (alaw) [Aug 7 14:46:01.409] DEBUG[17031] chan_sip.c: *** AST_CODEC_CHOOSE formats are alaw [Aug 7 14:46:01.409] DEBUG[17031] chan_sip.c: *** Our preferred formats from the incoming channel are (slin) [Aug 7 14:46:01.409] DEBUG[17031] chan_sip.c: This channel will not be able to handle video. [Aug 7 14:46:01.409] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 526 [Aug 7 14:46:01.409] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 526 [Aug 7 14:46:01.410] DEBUG[17031] res_stasis.c: issues: Subscribing to 1533645961.1 [Aug 7 14:46:01.410] DEBUG[17031] stasis/app.c: Channel '1533645961.1' is 1 interested in issues [Aug 7 14:46:01.410] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 506 [Aug 7 14:46:01.410] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 506 [Aug 7 14:46:01.410] DEBUG[17033] chan_sip.c: Outgoing Call for 611 [Aug 7 14:46:01.410] DEBUG[17033] chan_sip.c: Updating call counter for outgoing call [Aug 7 14:46:01.410] DEBUG[16797] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:46:01.410] DEBUG[16797] chan_sip.c: Checking device state for peer 611 [Aug 7 14:46:01.410] DEBUG[16797] devicestate.c: Changing state for SIP/611 - state 6 (Ringing) [Aug 7 14:46:01.410] DEBUG[16803] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:46:01.410] DEBUG[16803] devicestate.c: Checking provider Custom with Custom [Aug 7 14:46:01.410] DEBUG[16803] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:46:01.410] DEBUG[16803] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:46:01.410] DEBUG[16803] devicestate.c: Checking provider Custom with Custom [Aug 7 14:46:01.410] DEBUG[16803] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:46:01.410] DEBUG[17033] chan_sip.c: ** Our capability: (alaw) Video flag: False Text flag: False [Aug 7 14:46:01.410] DEBUG[17033] chan_sip.c: ** Our prefcodec: (slin) [Aug 7 14:46:01.410] DEBUG[17033] chan_sip.c: -- Done with adding codecs to SDP [Aug 7 14:46:01.410] DEBUG[17033] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [Aug 7 14:46:01.410] DEBUG[17033] chan_sip.c: Initializing initreq for method INVITE - callid 117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060 [Aug 7 14:46:01.410] DEBUG[17033] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:46:01.410] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:46:01.410] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:46:01.411] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 463 [Aug 7 14:46:01.411] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 463 [Aug 7 14:46:01.411] VERBOSE[17033] dial.c: Called 611 [Aug 7 14:46:01.411] DEBUG[17031] http.c: HTTP keeping session open. status_code:200 [Aug 7 14:46:01.416] DEBUG[16936] chan_sip.c: = Looking for Call ID: 117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060 (Checking To) --From tag as31297eb3 --To-tag [Aug 7 14:46:01.416] DEBUG[16936] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060' Request 102: Found [Aug 7 14:46:01.416] DEBUG[16936] chan_sip.c: SIP response 100 to standard invite [Aug 7 14:46:01.423] DEBUG[17032][C-00000001] res_rtp_asterisk.c: 0x7fbba0014640 -- Received RTP packet from 172.21.254.254:11796, dropping due to strict RTP protection. Qualifying new stream. [Aug 7 14:46:01.443] VERBOSE[17032][C-00000001] res_rtp_asterisk.c: 0x7fbba0014640 -- Strict RTP qualifying stream type: audio [Aug 7 14:46:01.443] DEBUG[17032][C-00000001] res_rtp_asterisk.c: 0x7fbba0014640 -- Received RTP packet from 172.21.254.254:11796, dropping due to strict RTP protection. Will switch to it in 3 packets. [Aug 7 14:46:01.444] DEBUG[16936] chan_sip.c: = Looking for Call ID: 117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060 (Checking To) --From tag as31297eb3 --To-tag 1-RKn3QMIWCD-g-8BslkCyXb4PtSeI37 [Aug 7 14:46:01.444] DEBUG[16936] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060' Request 102: Found [Aug 7 14:46:01.444] DEBUG[16936] chan_sip.c: SIP response 180 to standard invite [Aug 7 14:46:01.444] DEBUG[16797] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:46:01.444] DEBUG[16797] chan_sip.c: Checking device state for peer 611 [Aug 7 14:46:01.444] DEBUG[16797] devicestate.c: Changing state for SIP/611 - state 6 (Ringing) [Aug 7 14:46:01.444] DEBUG[16797] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:46:01.444] DEBUG[16797] chan_sip.c: Checking device state for peer 611 [Aug 7 14:46:01.444] DEBUG[16797] devicestate.c: Changing state for SIP/611 - state 6 (Ringing) [Aug 7 14:46:01.444] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 435 [Aug 7 14:46:01.444] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 435 [Aug 7 14:46:01.444] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 448 [Aug 7 14:46:01.444] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 448 [Aug 7 14:46:01.444] VERBOSE[17033] dial.c: SIP/611-00000001 is ringing [Aug 7 14:46:01.444] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 486 [Aug 7 14:46:01.444] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 486 [Aug 7 14:46:01.444] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 473 [Aug 7 14:46:01.444] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 473 [Aug 7 14:46:01.446] DEBUG[16803] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:46:01.446] DEBUG[16803] devicestate.c: Checking provider Custom with Custom [Aug 7 14:46:01.446] DEBUG[16803] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:46:01.446] DEBUG[16803] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:46:01.446] DEBUG[16803] devicestate.c: Checking provider Custom with Custom [Aug 7 14:46:01.447] DEBUG[16803] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:46:01.464] DEBUG[17032][C-00000001] res_rtp_asterisk.c: 0x7fbba0014640 -- Received RTP packet from 172.21.254.254:11796, dropping due to strict RTP protection. Will switch to it in 2 packets. [Aug 7 14:46:01.483] DEBUG[17032][C-00000001] res_rtp_asterisk.c: 0x7fbba0014640 -- Received RTP packet from 172.21.254.254:11796, dropping due to strict RTP protection. Will switch to it in 1 packets. [Aug 7 14:46:01.496] DEBUG[16936] chan_sip.c: = Looking for Call ID: 1998117674@192.168.10.120 (Checking From) --From tag 1179217472 --To-tag [Aug 7 14:46:01.496] DEBUG[16936] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Aug 7 14:46:01.496] DEBUG[16936] netsock2.c: Splitting '192.168.10.120:5062' into... [Aug 7 14:46:01.496] DEBUG[16936] netsock2.c: ...host '192.168.10.120' and port '5062'. [Aug 7 14:46:01.496] DEBUG[16936] chan_sip.c: NAT detected for 192.168.10.120 / 212.24.153.186 [Aug 7 14:46:01.496] DEBUG[16936] netsock2.c: Splitting 'stasis.daktela.com' into... [Aug 7 14:46:01.496] DEBUG[16936] netsock2.c: ...host 'stasis.daktela.com' and port ''. [Aug 7 14:46:01.496] DEBUG[16936] chan_sip.c: Store REGISTER's src-IP:port for call routing. [Aug 7 14:46:01.496] DEBUG[16936] chan_sip.c: build_path: do not use Path headers [Aug 7 14:46:01.496] DEBUG[16936] chan_sip.c: Allocating new SIP dialog for 76cf7aa370809dfa1adfa6630d21c381@95.80.200.221:5060 - OPTIONS (No RTP) [Aug 7 14:46:01.496] DEBUG[16936] acl.c: For destination '212.24.153.186', our source address is '95.80.200.221'. [Aug 7 14:46:01.496] DEBUG[16936] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:46:01.496] DEBUG[16936] chan_sip.c: SIP call-id changed from '76cf7aa370809dfa1adfa6630d21c381@95.80.200.221:5060' to '0c34fe375149f4d546aab4bd341a351f@95.80.200.221:5060' [Aug 7 14:46:01.496] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 234 [Aug 7 14:46:01.496] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 234 [Aug 7 14:46:01.496] DEBUG[16936] chan_sip.c: Initializing initreq for method OPTIONS - callid 0c34fe375149f4d546aab4bd341a351f@95.80.200.221:5060 [Aug 7 14:46:01.496] DEBUG[16936] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 212.24.153.186:5062 [Aug 7 14:46:01.496] VERBOSE[16936] 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:46:01.496] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 299 [Aug 7 14:46:01.496] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 299 [Aug 7 14:46:01.496] DEBUG[16936] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 212.24.153.186:5062 [Aug 7 14:46:01.496] DEBUG[16797] devicestate.c: No provider found, checking channel drivers for SIP - rozbitywell [Aug 7 14:46:01.497] DEBUG[16797] chan_sip.c: Checking device state for peer rozbitywell [Aug 7 14:46:01.497] DEBUG[16797] devicestate.c: Changing state for SIP/rozbitywell - state 1 (Not in use) [Aug 7 14:46:01.504] VERBOSE[17032][C-00000001] res_rtp_asterisk.c: 0x7fbba0014640 -- Strict RTP switching source address to 172.21.254.254:11796 [Aug 7 14:46:01.504] DEBUG[17032][C-00000001] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:46:01.504] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fbba0006498' [Aug 7 14:46:01.532] DEBUG[16936] chan_sip.c: = Looking for Call ID: 0c34fe375149f4d546aab4bd341a351f@95.80.200.221:5060 (Checking To) --From tag as49c07bc4 --To-tag 1339835180 [Aug 7 14:46:01.532] DEBUG[16936] chan_sip.c: Stopping retransmission on '0c34fe375149f4d546aab4bd341a351f@95.80.200.221:5060' of Request 102: Match Found [Aug 7 14:46:01.532] DEBUG[16936] chan_sip.c: Destroying SIP dialog 0c34fe375149f4d546aab4bd341a351f@95.80.200.221:5060 [Aug 7 14:46:02.446] DEBUG[16936] chan_sip.c: Auto destroying SIP dialog '25f17659650ff0372b16ae524705c921@test.test.com:5060' [Aug 7 14:46:02.446] DEBUG[16936] chan_sip.c: Destroying SIP dialog 25f17659650ff0372b16ae524705c921@test.test.com:5060 [Aug 7 14:46:03.855] DEBUG[17033] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.21.254.254:4013 [Aug 7 14:46:03.855] DEBUG[17033] res_rtp_asterisk.c: Got RTCP report of 64 bytes from 172.21.254.254:4013 [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: = Looking for Call ID: 117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060 (Checking To) --From tag as31297eb3 --To-tag 1-RKn3QMIWCD-g-8BslkCyXb4PtSeI37 [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Acked pending invite 102 [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Stopping retransmission on '117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060' of Request 102: Match Found [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: SIP response 200 to standard invite [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing session-level SDP o=- 3742634761 3742634762 IN IP4 10.255.255.167... OK. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing session-level SDP s=pjmedia... UNSUPPORTED OR FAILED. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing session-level SDP b=AS:117... UNSUPPORTED OR FAILED. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing session-level SDP a=X-nat:0... UNSUPPORTED OR FAILED. [Aug 7 14:46:03.855] DEBUG[16936] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7fbb80c3ed00 [Aug 7 14:46:03.855] DEBUG[16936] netsock2.c: Splitting '10.255.255.167' into... [Aug 7 14:46:03.855] DEBUG[16936] netsock2.c: ...host '10.255.255.167' and port ''. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP c=IN IP4 10.255.255.167... OK. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP b=TIAS:96000... UNSUPPORTED OR FAILED. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP a=rtcp:4013 IN IP4 10.255.255.167... UNSUPPORTED OR FAILED. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED OR FAILED. [Aug 7 14:46:03.855] DEBUG[16936] acl.c: For destination '10.255.255.167', our source address is '95.80.200.221'. [Aug 7 14:46:03.855] DEBUG[16936] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fbba80076a8' [Aug 7 14:46:03.855] VERBOSE[16936] res_rtp_asterisk.c: 0x7fbba8008620 -- Strict RTP learning after remote address set to: 10.255.255.167:4012 [Aug 7 14:46:03.855] DEBUG[16936] rtp_engine.c: Copying tx payload mapping 8 (0x7fbba0013220) from 0x7fbb80c3ed00 to 0x7fbba8007880 [Aug 7 14:46:03.855] DEBUG[16936] rtp_engine.c: Copying tx payload mapping 101 (0x7fbba0001620) from 0x7fbb80c3ed00 to 0x7fbba8007880 [Aug 7 14:46:03.855] DEBUG[16936] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fbba80076a8' [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: We're settling with these formats: (alaw) [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: We have an owner, now see if we need to change this call [Aug 7 14:46:03.855] DEBUG[16936] channel.c: Channel SIP/611-00000001 setting read format path: alaw -> alaw [Aug 7 14:46:03.855] DEBUG[16936] channel.c: Channel SIP/611-00000001 setting write format path: alaw -> alaw [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Updating call counter for outgoing call [Aug 7 14:46:03.855] DEBUG[16936] chan_sip.c: Trying to put 'ACK sip:611' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:46:03.856] DEBUG[16797] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:46:03.856] DEBUG[16797] chan_sip.c: Checking device state for peer 611 [Aug 7 14:46:03.856] DEBUG[16797] devicestate.c: Changing state for SIP/611 - state 2 (In use) [Aug 7 14:46:03.856] DEBUG[16803] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:46:03.856] DEBUG[16803] devicestate.c: Checking provider Custom with Custom [Aug 7 14:46:03.856] DEBUG[16803] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:46:03.856] VERBOSE[17033] dial.c: SIP/611-00000001 answered [Aug 7 14:46:03.856] DEBUG[16803] devicestate.c: Checking if I can find provider for "Custom" - number: StopCock611 [Aug 7 14:46:03.856] DEBUG[16803] devicestate.c: Checking provider Custom with Custom [Aug 7 14:46:03.856] DEBUG[16803] db.c: Unable to find key 'StopCock611' in family 'CustomDevstate' [Aug 7 14:46:03.856] VERBOSE[17033] ari/resource_channels.c: Launching Stasis(issues,second,1533645961.0,bridge_5b69948932f3e) on SIP/611-00000001 [Aug 7 14:46:03.856] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 443 [Aug 7 14:46:03.856] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 443 [Aug 7 14:46:03.856] DEBUG[17033] stasis/app.c: Channel '1533645961.1' is 2 interested in issues [Aug 7 14:46:03.856] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 480 [Aug 7 14:46:03.856] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 480 [Aug 7 14:46:03.856] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 430 [Aug 7 14:46:03.856] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 430 [Aug 7 14:46:03.856] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 475 [Aug 7 14:46:03.856] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 475 [Aug 7 14:46:03.856] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 467 [Aug 7 14:46:03.856] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 467 [Aug 7 14:46:03.856] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 462 [Aug 7 14:46:03.856] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 462 [Aug 7 14:46:03.856] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 479 [Aug 7 14:46:03.856] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 479 [Aug 7 14:46:03.857] DEBUG[17031] http.c: HTTP Request URI is /ari/bridges/bridge_5b69948932f3e/addChannel [Aug 7 14:46:03.857] DEBUG[16797] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:46:03.857] DEBUG[17031] http.c: match request [ari/bridges/bridge_5b69948932f3e/addChannel] with handler [httpstatus] len 10 [Aug 7 14:46:03.857] DEBUG[17031] http.c: match request [ari/bridges/bridge_5b69948932f3e/addChannel] with handler [static] len 6 [Aug 7 14:46:03.857] DEBUG[16797] chan_sip.c: Checking device state for peer 611 [Aug 7 14:46:03.857] DEBUG[17031] http.c: match request [ari/bridges/bridge_5b69948932f3e/addChannel] with handler [ari] len 3 [Aug 7 14:46:03.857] DEBUG[17031] http.c: Match made with [ari] [Aug 7 14:46:03.857] DEBUG[16797] devicestate.c: Changing state for SIP/611 - state 2 (In use) [Aug 7 14:46:03.857] DEBUG[17031] http.c: HTTP consuming request body [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Finding handler for bridges [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Checking playbacks [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Checking channels [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Checking asterisk [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Checking events [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Checking bridges [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Finding handler for bridge_5b69948932f3e [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Checking bridgeId [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Finding handler for addChannel [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Checking addChannel [Aug 7 14:46:03.857] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:03.857] DEBUG[17031] stasis/control.c: 1533645961.1: Sending channel add_to_bridge command [Aug 7 14:46:03.879] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 48 bytes from 172.21.254.254:11797 [Aug 7 14:46:04.013] DEBUG[17033] bridge_roles.c: Roles did not exist on channel SIP/611-00000001 [Aug 7 14:46:04.013] DEBUG[17033] stasis/control.c: 1533645961.1: Adding to bridge bridge_5b69948932f3e [Aug 7 14:46:04.013] DEBUG[17033] stasis/app.c: Bridge 'bridge_5b69948932f3e' is 3 interested in issues [Aug 7 14:46:04.013] DEBUG[17034] bridge_channel.c: Bridge bridge_5b69948932f3e: 0x7fbbb80034f8(SIP/611-00000001) is joining [Aug 7 14:46:04.013] DEBUG[17034] bridge_channel.c: Bridge bridge_5b69948932f3e: pushing 0x7fbbb80034f8(SIP/611-00000001) [Aug 7 14:46:04.013] VERBOSE[17034] bridge_channel.c: Channel SIP/611-00000001 joined 'simple_bridge' stasis-bridge [Aug 7 14:46:04.013] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 651 [Aug 7 14:46:04.013] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 651 [Aug 7 14:46:04.013] DEBUG[17034] dahdi/bridge_native_dahdi.c: Channel 'SIP/322-00000000' is not DAHDI. [Aug 7 14:46:04.013] DEBUG[17034] dahdi/bridge_native_dahdi.c: Bridge bridge_5b69948932f3e: Cannot use native DAHDI. Channel 'SIP/322-00000000' not compatible. [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:46:04.013] DEBUG[17034] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Checking compatability for channels 'SIP/322-00000000' and 'SIP/611-00000001' [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Chose bridge technology native_rtp [Aug 7 14:46:04.013] VERBOSE[17034] bridge.c: Bridge bridge_5b69948932f3e: switching from simple_bridge technology to native_rtp [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge bridge_5b69948932f3e: calling native_rtp technology constructor [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge bridge_5b69948932f3e: moving 0x7fbba0011288(SIP/322-00000000) to dummy bridge temporarily [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge bridge_5b69948932f3e: 0x7fbba0011288(SIP/322-00000000) is leaving simple_bridge technology (dummy) [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge bridge_5b69948932f3e: calling simple_bridge technology stop [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge bridge_5b69948932f3e: 0x7fbbb80034f8(SIP/611-00000001) is joining native_rtp technology [Aug 7 14:46:04.013] DEBUG[17034] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Channel 'SIP/611-00000001' is joining bridge tech [Aug 7 14:46:04.013] DEBUG[17034] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Attaching hook data 0x7fbbc00010c0 to 'SIP/611-00000001' [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge bridge_5b69948932f3e: 0x7fbba0011288(SIP/322-00000000) is joining native_rtp technology [Aug 7 14:46:04.013] DEBUG[17034] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Channel 'SIP/322-00000000' is joining bridge tech [Aug 7 14:46:04.013] DEBUG[17034] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Attaching hook data 0x7fbbc0002190 to 'SIP/322-00000000' [Aug 7 14:46:04.013] DEBUG[17034] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Tech starting 'SIP/611-00000001' and 'SIP/322-00000000' with target 'none' [Aug 7 14:46:04.013] VERBOSE[17034] bridge_native_rtp.c: Locally RTP bridged 'SIP/611-00000001' and 'SIP/322-00000000' in stack [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge bridge_5b69948932f3e: calling native_rtp technology start [Aug 7 14:46:04.013] DEBUG[17034] bridge.c: Bridge bridge_5b69948932f3e: calling simple_bridge technology destructor [Aug 7 14:46:04.013] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:46:04.013] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:46:04.013] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:46:04.013] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:46:04.014] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:46:04.014] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:46:04.014] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 490 [Aug 7 14:46:04.014] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 490 [Aug 7 14:46:04.014] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 493 [Aug 7 14:46:04.014] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 493 [Aug 7 14:46:04.014] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 480 [Aug 7 14:46:04.014] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 480 [Aug 7 14:46:04.014] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 533 [Aug 7 14:46:04.014] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 533 [Aug 7 14:46:04.014] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 520 [Aug 7 14:46:04.014] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 520 [Aug 7 14:46:04.014] DEBUG[17034] res_rtp_asterisk.c: Changing ssrc from 388989776 to 1945151812 due to a source change [Aug 7 14:46:04.014] DEBUG[17032][C-00000001] dahdi/bridge_native_dahdi.c: Channel 'SIP/611-00000001' is not DAHDI. [Aug 7 14:46:04.014] DEBUG[17032][C-00000001] dahdi/bridge_native_dahdi.c: Bridge bridge_5b69948932f3e: Cannot use native DAHDI. Channel 'SIP/611-00000001' not compatible. [Aug 7 14:46:04.014] DEBUG[17032][C-00000001] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:46:04.014] DEBUG[17032][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:46:04.014] DEBUG[17033] stasis/app.c: Bridge 'bridge_5b69948932f3e' is 4 interested in issues [Aug 7 14:46:04.014] DEBUG[17032][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Checking compatability for channels 'SIP/611-00000001' and 'SIP/322-00000000' [Aug 7 14:46:04.014] DEBUG[17032][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:46:04.014] DEBUG[17032][C-00000001] bridge.c: Bridge technology simple_bridge has less preference than native_rtp (50 <= 90). Skipping. [Aug 7 14:46:04.014] DEBUG[17032][C-00000001] bridge.c: Chose bridge technology native_rtp [Aug 7 14:46:04.014] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e is already using the new technology. [Aug 7 14:46:04.014] DEBUG[17031] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:46:04.014] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:46:04.014] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:46:04.015] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:46:04.015] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:46:04.015] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 493 [Aug 7 14:46:04.015] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 493 [Aug 7 14:46:04.015] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 533 [Aug 7 14:46:04.015] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 533 [Aug 7 14:46:04.015] DEBUG[17032][C-00000001] chan_sip.c: ** Our capability: (alaw) Video flag: True Text flag: True [Aug 7 14:46:04.015] DEBUG[17032][C-00000001] chan_sip.c: ** Our prefcodec: (nothing) [Aug 7 14:46:04.015] DEBUG[17032][C-00000001] chan_sip.c: -- Done with adding codecs to SDP [Aug 7 14:46:04.015] DEBUG[17032][C-00000001] chan_sip.c: Setting framing on incoming call: 20 [Aug 7 14:46:04.015] DEBUG[17032][C-00000001] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [Aug 7 14:46:04.015] DEBUG[17032][C-00000001] chan_sip.c: Initializing already initialized SIP dialog 1808813369@10.255.255.157 (presumably reinvite) [Aug 7 14:46:04.015] DEBUG[17032][C-00000001] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 172.21.254.254:5063 [Aug 7 14:46:04.015] DEBUG[16786] threadpool.c: Increasing threadpool stasis-core's size by 1 [Aug 7 14:46:04.015] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:46:04.015] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:46:04.015] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 490 [Aug 7 14:46:04.015] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 490 [Aug 7 14:46:04.015] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 480 [Aug 7 14:46:04.015] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 480 [Aug 7 14:46:04.015] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 520 [Aug 7 14:46:04.015] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 520 [Aug 7 14:46:04.015] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 453 [Aug 7 14:46:04.015] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 453 [Aug 7 14:46:04.015] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 466 [Aug 7 14:46:04.015] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 466 [Aug 7 14:46:04.016] DEBUG[17031] http.c: HTTP Request URI is /ari/channels/1533645961.0/hold [Aug 7 14:46:04.016] DEBUG[17031] http.c: match request [ari/channels/1533645961.0/hold] with handler [httpstatus] len 10 [Aug 7 14:46:04.016] DEBUG[17031] http.c: match request [ari/channels/1533645961.0/hold] with handler [static] len 6 [Aug 7 14:46:04.016] DEBUG[17031] http.c: match request [ari/channels/1533645961.0/hold] with handler [ari] len 3 [Aug 7 14:46:04.016] DEBUG[17031] http.c: Match made with [ari] [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Finding handler for channels [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking playbacks [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking channels [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Finding handler for 1533645961.0 [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking create [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking channelId [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Finding handler for hold [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking continue [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking redirect [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking answer [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking ring [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking dtmf [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking mute [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking hold [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:04.016] DEBUG[17031] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:46:04.016] DEBUG[17030][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Tech stopping 'SIP/611-00000001' and 'SIP/322-00000000' with target 'SIP/322-00000000' [Aug 7 14:46:04.016] DEBUG[17030][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:46:04.016] DEBUG[17030][C-00000001] res_rtp_asterisk.c: Setting the marker bit due to a source update [Aug 7 14:46:04.016] VERBOSE[17030][C-00000001] res_musiconhold.c: Started music on hold, class 'default', on channel 'SIP/322-00000000' [Aug 7 14:46:04.016] DEBUG[17030][C-00000001] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Aug 7 14:46:04.016] DEBUG[17031] http.c: HTTP Request URI is /ari/channels/1533645961.0/mute [Aug 7 14:46:04.016] DEBUG[17031] http.c: match request [ari/channels/1533645961.0/mute] with handler [httpstatus] len 10 [Aug 7 14:46:04.016] DEBUG[17031] http.c: match request [ari/channels/1533645961.0/mute] with handler [static] len 6 [Aug 7 14:46:04.016] DEBUG[17031] http.c: match request [ari/channels/1533645961.0/mute] with handler [ari] len 3 [Aug 7 14:46:04.016] DEBUG[17031] http.c: Match made with [ari] [Aug 7 14:46:04.016] DEBUG[17031] http.c: HTTP consuming request body [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Finding handler for channels [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking playbacks [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking channels [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Finding handler for 1533645961.0 [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking create [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking channelId [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Finding handler for mute [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking continue [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking redirect [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking answer [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking ring [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking dtmf [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Checking mute [Aug 7 14:46:04.016] DEBUG[17031] res_ari.c: Got it! [Aug 7 14:46:04.016] DEBUG[17031] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] dahdi/bridge_native_dahdi.c: Channel 'SIP/611-00000001' is not DAHDI. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] dahdi/bridge_native_dahdi.c: Bridge bridge_5b69948932f3e: Cannot use native DAHDI. Channel 'SIP/611-00000001' not compatible. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Checking compatability for channels 'SIP/611-00000001' and 'SIP/322-00000000' [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e' can not use native RTP bridge as channel 'SIP/322-00000000' has features which prevent it [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Chose bridge technology simple_bridge [Aug 7 14:46:04.016] VERBOSE[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: switching from native_rtp technology to simple_bridge [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: calling simple_bridge technology constructor [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: moving 0x7fbbb80034f8(SIP/611-00000001) to dummy bridge temporarily [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: moving 0x7fbba0011288(SIP/322-00000000) to dummy bridge temporarily [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: 0x7fbbb80034f8(SIP/611-00000001) is leaving native_rtp technology (dummy) [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Channel 'SIP/611-00000001' is leaving bridge tech [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Detaching hook data 0x7fbbc0001130 from 'SIP/611-00000001' [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Tech stopping 'SIP/611-00000001' and 'SIP/322-00000000' with target 'none' [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge_native_rtp.c: Destroying channel tech_pvt data 0x7fbbc00010c0 [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: 0x7fbba0011288(SIP/322-00000000) is leaving native_rtp technology (dummy) [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Channel 'SIP/322-00000000' is leaving bridge tech [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Detaching hook data 0x7fbbc0002200 from 'SIP/322-00000000' [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge_native_rtp.c: Destroying channel tech_pvt data 0x7fbbc0002190 [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: calling native_rtp technology stop [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: 0x7fbbb80034f8(SIP/611-00000001) is joining simple_bridge technology [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] channel.c: Channel SIP/322-00000000 setting read format path: alaw -> alaw [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] channel.c: Channel SIP/611-00000001 setting write format path: alaw -> alaw [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] channel.c: Channel SIP/611-00000001 setting read format path: alaw -> alaw [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] channel.c: Channel SIP/322-00000000 setting write format path: alaw -> alaw [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] channel.c: Channel SIP/322-00000000 setting write format path: alaw -> alaw [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: 0x7fbba0011288(SIP/322-00000000) is joining simple_bridge technology [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] channel.c: Channel SIP/322-00000000 setting read format path: alaw -> alaw [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] channel.c: Channel SIP/611-00000001 setting write format path: alaw -> alaw [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] channel.c: Channel SIP/611-00000001 setting read format path: alaw -> alaw [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] channel.c: Channel SIP/322-00000000 setting write format path: alaw -> alaw [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] channel.c: Channel SIP/322-00000000 setting write format path: alaw -> alaw [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: calling simple_bridge technology start [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e: calling native_rtp technology destructor [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 510 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 510 [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] dahdi/bridge_native_dahdi.c: Channel 'SIP/611-00000001' is not DAHDI. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] dahdi/bridge_native_dahdi.c: Bridge bridge_5b69948932f3e: Cannot use native DAHDI. Channel 'SIP/611-00000001' not compatible. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Checking compatability for channels 'SIP/611-00000001' and 'SIP/322-00000000' [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e' can not use native RTP bridge as channel 'SIP/322-00000000' has features which prevent it [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Chose bridge technology simple_bridge [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 550 [Aug 7 14:46:04.016] DEBUG[17032][C-00000001] bridge.c: Bridge bridge_5b69948932f3e is already using the new technology. [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 550 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 510 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 510 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 550 [Aug 7 14:46:04.016] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 550 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 490 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 490 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 497 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 497 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 537 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 537 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 490 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 490 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 497 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 497 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 537 [Aug 7 14:46:04.017] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 537 [Aug 7 14:46:04.018] DEBUG[17034] dahdi/bridge_native_dahdi.c: Channel 'SIP/611-00000001' is not DAHDI. [Aug 7 14:46:04.018] DEBUG[17034] dahdi/bridge_native_dahdi.c: Bridge bridge_5b69948932f3e: Cannot use native DAHDI. Channel 'SIP/611-00000001' not compatible. [Aug 7 14:46:04.018] DEBUG[17034] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Aug 7 14:46:04.018] DEBUG[17034] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Aug 7 14:46:04.018] DEBUG[17034] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e'. Checking compatability for channels 'SIP/611-00000001' and 'SIP/322-00000000' [Aug 7 14:46:04.018] DEBUG[17034] bridge_native_rtp.c: Bridge 'bridge_5b69948932f3e' can not use native RTP bridge as channel 'SIP/322-00000000' has features which prevent it [Aug 7 14:46:04.018] DEBUG[17034] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Aug 7 14:46:04.018] DEBUG[17034] bridge.c: Bridge technology softmix does not have any capabilities we want. [Aug 7 14:46:04.018] DEBUG[17034] bridge.c: Chose bridge technology simple_bridge [Aug 7 14:46:04.018] DEBUG[17034] bridge.c: Bridge bridge_5b69948932f3e is already using the new technology. [Aug 7 14:46:04.018] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 489 [Aug 7 14:46:04.018] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 489 [Aug 7 14:46:04.018] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 476 [Aug 7 14:46:04.018] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 476 [Aug 7 14:46:04.019] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 503 [Aug 7 14:46:04.019] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 503 [Aug 7 14:46:04.019] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 490 [Aug 7 14:46:04.019] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 490 [Aug 7 14:46:04.019] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 510 [Aug 7 14:46:04.019] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 510 [Aug 7 14:46:04.019] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 497 [Aug 7 14:46:04.019] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 497 [Aug 7 14:46:04.019] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 550 [Aug 7 14:46:04.019] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 550 [Aug 7 14:46:04.019] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 537 [Aug 7 14:46:04.019] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 537 [Aug 7 14:46:04.020] DEBUG[16982] res_http_websocket.c: Writing websocket string of length 457 [Aug 7 14:46:04.020] DEBUG[16982] res_http_websocket.c: Writing websocket text frame, length 457 [Aug 7 14:46:04.020] DEBUG[16997] res_http_websocket.c: Writing websocket string of length 444 [Aug 7 14:46:04.020] DEBUG[16997] res_http_websocket.c: Writing websocket text frame, length 444 [Aug 7 14:46:04.020] DEBUG[17034] chan_sip.c: ** Our capability: (alaw) Video flag: True Text flag: True [Aug 7 14:46:04.020] DEBUG[17034] chan_sip.c: ** Our prefcodec: (slin) [Aug 7 14:46:04.020] DEBUG[17034] chan_sip.c: -- Done with adding codecs to SDP [Aug 7 14:46:04.020] DEBUG[17034] chan_sip.c: Done building SDP. Settling with this capability: (alaw) [Aug 7 14:46:04.020] DEBUG[17034] chan_sip.c: Initializing already initialized SIP dialog 117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060 (presumably reinvite) [Aug 7 14:46:04.020] DEBUG[17034] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:46:04.020] DEBUG[17034] res_rtp_asterisk.c: 0x7fbba8008620 -- Received RTP packet from 172.21.254.254:4012, dropping due to strict RTP protection. Qualifying new stream. [Aug 7 14:46:04.024] VERBOSE[17034] res_rtp_asterisk.c: 0x7fbba8008620 -- Strict RTP qualifying stream type: audio [Aug 7 14:46:04.024] DEBUG[17034] res_rtp_asterisk.c: 0x7fbba8008620 -- Received RTP packet from 172.21.254.254:4012, dropping due to strict RTP protection. Will switch to it in 3 packets. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: = Looking for Call ID: 117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060 (Checking To) --From tag as31297eb3 --To-tag 1-RKn3QMIWCD-g-8BslkCyXb4PtSeI37 [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Acked pending invite 103 [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Stopping retransmission on '117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060' of Request 103: Match Found [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: SIP response 200 to RE-invite on outgoing call 117a230a34c06e3051e3ab18634e13c3@95.80.200.221:5060 [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing session-level SDP o=- 3742634761 3742634763 IN IP4 10.255.255.167... OK. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing session-level SDP s=pjmedia... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing session-level SDP b=AS:117... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing session-level SDP a=X-nat:0... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.025] DEBUG[16936] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7fbb80c3ed00 [Aug 7 14:46:04.025] DEBUG[16936] netsock2.c: Splitting '10.255.255.167' into... [Aug 7 14:46:04.025] DEBUG[16936] netsock2.c: ...host '10.255.255.167' and port ''. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP c=IN IP4 10.255.255.167... OK. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP b=TIAS:96000... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP a=rtcp:4013 IN IP4 10.255.255.167... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.025] DEBUG[16936] acl.c: For destination '10.255.255.167', our source address is '95.80.200.221'. [Aug 7 14:46:04.025] DEBUG[16936] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fbba80076a8' [Aug 7 14:46:04.025] VERBOSE[16936] res_rtp_asterisk.c: 0x7fbba8008620 -- Strict RTP learning after remote address set to: 10.255.255.167:4012 [Aug 7 14:46:04.025] DEBUG[16936] rtp_engine.c: Copying tx payload mapping 8 (0x7fbba00110d0) from 0x7fbb80c3ed00 to 0x7fbba8007880 [Aug 7 14:46:04.025] DEBUG[16936] rtp_engine.c: Copying tx payload mapping 101 (0x7fbba0024930) from 0x7fbb80c3ed00 to 0x7fbba8007880 [Aug 7 14:46:04.025] DEBUG[16936] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fbba80076a8' [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: We're settling with these formats: (alaw) [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: We have an owner, now see if we need to change this call [Aug 7 14:46:04.025] DEBUG[16936] channel.c: Channel SIP/611-00000001 setting read format path: alaw -> alaw [Aug 7 14:46:04.025] DEBUG[16936] channel.c: Channel SIP/611-00000001 setting write format path: alaw -> alaw [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Updating call counter for outgoing call [Aug 7 14:46:04.025] DEBUG[16936] chan_sip.c: Trying to put 'ACK sip:611' onto UDP socket destined for 172.21.254.254:59299 [Aug 7 14:46:04.025] DEBUG[16797] devicestate.c: No provider found, checking channel drivers for SIP - 611 [Aug 7 14:46:04.025] DEBUG[16797] chan_sip.c: Checking device state for peer 611 [Aug 7 14:46:04.025] DEBUG[16797] devicestate.c: Changing state for SIP/611 - state 2 (In use) [Aug 7 14:46:04.035] DEBUG[16936] chan_sip.c: = Looking for Call ID: 1808813369@10.255.255.157 (Checking To) --From tag as61032b85 --To-tag 3714664092 [Aug 7 14:46:04.035] DEBUG[16936][C-00000001] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1808813369@10.255.255.157' Request 102: Found [Aug 7 14:46:04.035] DEBUG[16936][C-00000001] chan_sip.c: SIP response 100 to RE-invite on outgoing call 1808813369@10.255.255.157 [Aug 7 14:46:04.036] DEBUG[17032][C-00000001] media_cache.c: Failed to obtain media at '/var/lib/asterisk/mohmp3//TristeAlegriaPromo' [Aug 7 14:46:04.036] DEBUG[17032][C-00000001] media_cache.c: Failed to obtain media at '/var/lib/asterisk/mohmp3//TristeAlegriaPromo' [Aug 7 14:46:04.036] DEBUG[17032][C-00000001] channel.c: Channel SIP/322-00000000 setting write format path: slin -> alaw [Aug 7 14:46:04.036] DEBUG[17032][C-00000001] res_musiconhold.c: SIP/322-00000000 Opened file 0 '/var/lib/asterisk/mohmp3//TristeAlegriaPromo' [Aug 7 14:46:04.046] DEBUG[17034] res_rtp_asterisk.c: 0x7fbba8008620 -- Received RTP packet from 172.21.254.254:4012, dropping due to strict RTP protection. Qualifying new stream. [Aug 7 14:46:04.070] DEBUG[17034] res_rtp_asterisk.c: 0x7fbba8008620 -- Received RTP packet from 172.21.254.254:4012, dropping due to strict RTP protection. Will switch to it in 3 packets. [Aug 7 14:46:04.081] DEBUG[17034] res_rtp_asterisk.c: 0x7fbba8008620 -- Received RTP packet from 172.21.254.254:4012, dropping due to strict RTP protection. Will switch to it in 2 packets. [Aug 7 14:46:04.104] DEBUG[17034] res_rtp_asterisk.c: 0x7fbba8008620 -- Received RTP packet from 172.21.254.254:4012, dropping due to strict RTP protection. Will switch to it in 1 packets. [Aug 7 14:46:04.127] VERBOSE[17034] res_rtp_asterisk.c: 0x7fbba8008620 -- Strict RTP switching source address to 172.21.254.254:4012 [Aug 7 14:46:04.127] DEBUG[17034] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:46:04.127] DEBUG[17034] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fbba80076a8' [Aug 7 14:46:04.144] DEBUG[16936] chan_sip.c: = Looking for Call ID: 1808813369@10.255.255.157 (Checking To) --From tag as61032b85 --To-tag 3714664092 [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Acked pending invite 102 [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Stopping retransmission on '1808813369@10.255.255.157' of Request 102: Match Found [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: SIP response 200 to RE-invite on outgoing call 1808813369@10.255.255.157 [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Processing session-level SDP o=- 20030 20031 IN IP4 10.255.255.157... OK. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Processing session-level SDP s=SDP data... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] netsock2.c: Splitting '10.255.255.157' into... [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] netsock2.c: ...host '10.255.255.157' and port ''. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Processing session-level SDP c=IN IP4 10.255.255.157... OK. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7fbb80c3ed00 [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Setting framing to 20 [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] acl.c: For destination '10.255.255.157', our source address is '95.80.200.221'. [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fbba0006498' [Aug 7 14:46:04.144] VERBOSE[16936][C-00000001] res_rtp_asterisk.c: 0x7fbba0014640 -- Strict RTP learning after remote address set to: 10.255.255.157:11796 [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] rtp_engine.c: Copying tx payload mapping 8 (0x7fbba0012960) from 0x7fbb80c3ed00 to 0x7fbba0006670 [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] rtp_engine.c: Copying tx payload mapping 101 (0x7fbba0001620) from 0x7fbb80c3ed00 to 0x7fbba0006670 [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7fbba0006498' [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: We're settling with these formats: (alaw) [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: We have an owner, now see if we need to change this call [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] channel.c: Channel SIP/322-00000000 setting read format path: alaw -> alaw [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Updating call counter for incoming call [Aug 7 14:46:04.144] DEBUG[16936][C-00000001] chan_sip.c: Trying to put 'ACK sip:322' onto UDP socket destined for 172.21.254.254:5063 [Aug 7 14:46:04.144] DEBUG[16797] devicestate.c: No provider found, checking channel drivers for SIP - 322 [Aug 7 14:46:04.144] DEBUG[16797] chan_sip.c: Checking device state for peer 322 [Aug 7 14:46:04.144] DEBUG[16797] devicestate.c: Changing state for SIP/322 - state 2 (In use) [Aug 7 14:46:04.144] DEBUG[17032][C-00000001] acl.c: For destination '172.21.254.254', our source address is '95.80.200.221'. [Aug 7 14:46:04.144] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7fbba0006498' [Aug 7 14:46:04.156] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Ooh, format changed from none to alaw [Aug 7 14:46:08.830] DEBUG[17034] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4013 [Aug 7 14:46:08.879] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11797 [Aug 7 14:46:09.027] VERBOSE[17034] res_rtp_asterisk.c: 0x7fbba8008620 -- Strict RTP learning complete - Locking on source address 172.21.254.254:4012 [Aug 7 14:46:09.145] VERBOSE[17032][C-00000001] res_rtp_asterisk.c: 0x7fbba0014640 -- Strict RTP learning complete - Locking on source address 172.21.254.254:11796 [Aug 7 14:46:11.388] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11797 [Aug 7 14:46:11.408] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11797 [Aug 7 14:46:13.649] DEBUG[17034] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4013 [Aug 7 14:46:13.873] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11797 [Aug 7 14:46:14.026] DEBUG[17031] iostream.c: TCP timeout reading data [Aug 7 14:46:14.026] DEBUG[17031] http.c: HTTP closing session. Top level [Aug 7 14:46:18.466] DEBUG[17034] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4013 [Aug 7 14:46:18.873] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11797 [Aug 7 14:46:21.389] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11797 [Aug 7 14:46:21.408] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11797 [Aug 7 14:46:23.285] DEBUG[17034] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4013 [Aug 7 14:46:23.879] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11797 [Aug 7 14:46:24.017] DEBUG[17035] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 7 14:46:24.017] DEBUG[16786] threadpool.c: Destroying worker thread 18 [Aug 7 14:46:24.020] DEBUG[17029] threadpool.c: Worker thread idle timeout reached. Dying. [Aug 7 14:46:24.020] DEBUG[16786] threadpool.c: Destroying worker thread 17 [Aug 7 14:46:24.184] DEBUG[17045] http.c: HTTP opening session. Top level [Aug 7 14:46:24.184] DEBUG[17045] http.c: HTTP Request URI is /ari/channels/1533645961.1/ring [Aug 7 14:46:24.184] DEBUG[17045] http.c: match request [ari/channels/1533645961.1/ring] with handler [httpstatus] len 10 [Aug 7 14:46:24.184] DEBUG[17045] http.c: match request [ari/channels/1533645961.1/ring] with handler [static] len 6 [Aug 7 14:46:24.184] DEBUG[17045] http.c: match request [ari/channels/1533645961.1/ring] with handler [ari] len 3 [Aug 7 14:46:24.184] DEBUG[17045] http.c: Match made with [ari] [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Finding handler for channels [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Checking playbacks [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Checking channels [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Got it! [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Finding handler for 1533645961.1 [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Checking create [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Checking channelId [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Got it! [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Finding handler for ring [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Checking continue [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Checking redirect [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Checking answer [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Checking ring [Aug 7 14:46:24.184] DEBUG[17045] res_ari.c: Got it! [Aug 7 14:46:24.184] DEBUG[17033] channel.c: Driver for channel 'SIP/611-00000001' does not support indication 3, emulating it [Aug 7 14:46:24.184] DEBUG[17033] channel.c: Channel SIP/611-00000001 setting write format path: slin -> alaw [Aug 7 14:46:24.184] DEBUG[17033] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Aug 7 14:46:24.184] DEBUG[17045] http.c: HTTP keeping session open. status_code:204 [Aug 7 14:46:24.185] DEBUG[17045] http.c: HTTP closing session. Top level [Aug 7 14:46:24.203] DEBUG[16938] chan_iax2.c: ip callno count decremented to 0 for 127.0.0.1 [Aug 7 14:46:24.203] DEBUG[16944] chan_iax2.c: ip callno count incremented to 1 for 127.0.0.1 [Aug 7 14:46:24.203] DEBUG[16946] chan_iax2.c: schedule decrement of callno used for 127.0.0.1 in 60 seconds [Aug 7 14:46:24.203] DEBUG[16946] chan_iax2.c: Peer loopback: got pong, lastms 3, historicms 3, maxms 2000 [Aug 7 14:46:24.204] DEBUG[17034] res_rtp_asterisk.c: Ooh, format changed from none to alaw [Aug 7 14:46:24.388] DEBUG[17034] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4013 [Aug 7 14:46:26.388] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11797 [Aug 7 14:46:26.408] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11797 [Aug 7 14:46:28.104] DEBUG[17034] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4013 [Aug 7 14:46:28.879] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11797 [Aug 7 14:46:30.442] DEBUG[16936] chan_sip.c: Allocating new SIP dialog for 34ae7e8673dcab465e76c3973c6ab921@95.80.200.221:5060 - OPTIONS (No RTP) [Aug 7 14:46:30.442] DEBUG[16936] acl.c: For destination 'test.test.com', our source address is '95.80.200.221'. [Aug 7 14:46:30.442] DEBUG[16936] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:46:30.442] DEBUG[16936] chan_sip.c: SIP call-id changed from '34ae7e8673dcab465e76c3973c6ab921@95.80.200.221:5060' to '4300d28c506b8c056d85988a140eb875@95.80.200.221:5060' [Aug 7 14:46:30.442] DEBUG[16936] chan_sip.c: Initializing initreq for method OPTIONS - callid 4300d28c506b8c056d85988a140eb875@95.80.200.221:5060 [Aug 7 14:46:30.442] DEBUG[16936] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for test.test.com:5060 [Aug 7 14:46:30.443] DEBUG[16936] chan_sip.c: = Looking for Call ID: 4300d28c506b8c056d85988a140eb875@95.80.200.221:5060 (Checking To) --From tag as3c7ea100 --To-tag as6a4229b6 [Aug 7 14:46:30.443] DEBUG[16936] chan_sip.c: Stopping retransmission on '4300d28c506b8c056d85988a140eb875@95.80.200.221:5060' of Request 102: Match Found [Aug 7 14:46:30.443] DEBUG[16936] chan_sip.c: Destroying SIP dialog 4300d28c506b8c056d85988a140eb875@95.80.200.221:5060 [Aug 7 14:46:30.446] DEBUG[16936] chan_sip.c: = Looking for Call ID: 4f0a61126fe2b91569f30a6625114c65@test.test.com:5060 (Checking From) --From tag as564ee6bb --To-tag [Aug 7 14:46:30.446] DEBUG[16936] acl.c: For destination 'test.test.com', our source address is '95.80.200.221'. [Aug 7 14:46:30.446] DEBUG[16936] chan_sip.c: Setting AST_TRANSPORT_UDP with address 95.80.200.221:5060 [Aug 7 14:46:30.446] DEBUG[16936] netsock2.c: Splitting 'test.test.com:5060' into... [Aug 7 14:46:30.446] DEBUG[16936] netsock2.c: ...host 'test.test.com' and port '5060'. [Aug 7 14:46:30.446] DEBUG[16936] chan_sip.c: Allocating new SIP dialog for 4f0a61126fe2b91569f30a6625114c65@test.test.com:5060 - OPTIONS (No RTP) [Aug 7 14:46:30.446] DEBUG[16936] chan_sip.c: **** Received OPTIONS (3) - Command in SIP OPTIONS [Aug 7 14:46:30.446] DEBUG[16936] netsock2.c: Splitting '95.80.200.221:5060' into... [Aug 7 14:46:30.446] DEBUG[16936] netsock2.c: ...host '95.80.200.221' and port ''. [Aug 7 14:46:30.446] DEBUG[16936] netsock2.c: Splitting 'test.test.com' into... [Aug 7 14:46:30.446] DEBUG[16936] netsock2.c: ...host 'test.test.com' and port ''. [Aug 7 14:46:30.446] DEBUG[16936] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for test.test.com:5060 [Aug 7 14:46:31.388] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11797 [Aug 7 14:46:31.408] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11797 [Aug 7 14:46:32.922] DEBUG[17034] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4013 [Aug 7 14:46:33.497] DEBUG[16936] chan_sip.c: Auto destroying SIP dialog '1998117674@192.168.10.120' [Aug 7 14:46:33.497] DEBUG[16936] chan_sip.c: Destroying SIP dialog 1998117674@192.168.10.120 [Aug 7 14:46:33.879] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11797 [Aug 7 14:46:36.388] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 28 bytes from 172.21.254.254:11797 [Aug 7 14:46:36.408] DEBUG[17032][C-00000001] res_rtp_asterisk.c: Got RTCP report of 72 bytes from 172.21.254.254:11797 [Aug 7 14:46:37.753] DEBUG[17034] res_rtp_asterisk.c: Got RTCP report of 84 bytes from 172.21.254.254:4013