[Jul 9 14:50:02] Asterisk 13.4.0 built by root @ asterisk-1 on a x86_64 running Linux on 2015-07-03 11:06:05 UTC [Jul 9 14:50:04] DEBUG[9104] chan_sip.c: Allocating new SIP dialog for 06e5b17d1c3d4bee1864d30577017fe4@127.0.0.1:5060 - OPTIONS (No RTP) [Jul 9 14:50:04] DEBUG[9104] acl.c: For destination '192.168.1.199', our source address is '192.168.1.146'. [Jul 9 14:50:04] DEBUG[9104] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.1.146:5060 [Jul 9 14:50:04] DEBUG[9104] chan_sip.c: SIP call-id changed from '06e5b17d1c3d4bee1864d30577017fe4@127.0.0.1:5060' to '184a7eb04c6ca05159580a7b23bda1b9@192.168.1.146:5060' [Jul 9 14:50:04] DEBUG[9104] chan_sip.c: Initializing initreq for method OPTIONS - callid 184a7eb04c6ca05159580a7b23bda1b9@192.168.1.146:5060 [Jul 9 14:50:04] DEBUG[9104] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.1.199:55180 [Jul 9 14:50:04] DEBUG[9104] chan_sip.c: = Looking for Call ID: 184a7eb04c6ca05159580a7b23bda1b9@192.168.1.146:5060 (Checking To) --From tag as52ffe717 --To-tag 721bc700 [Jul 9 14:50:04] DEBUG[9104] chan_sip.c: Stopping retransmission on '184a7eb04c6ca05159580a7b23bda1b9@192.168.1.146:5060' of Request 102: Match Found [Jul 9 14:50:04] DEBUG[9104] chan_sip.c: Destroying SIP dialog 184a7eb04c6ca05159580a7b23bda1b9@192.168.1.146:5060 [Jul 9 14:50:34] DEBUG[9104] chan_sip.c: Allocating new SIP dialog for 315399090ed08f106ddaa11563ae5688@127.0.0.1:5060 - OPTIONS (No RTP) [Jul 9 14:50:34] DEBUG[9104] acl.c: For destination '192.168.1.143', our source address is '192.168.1.146'. [Jul 9 14:50:34] DEBUG[9104] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.1.146:5060 [Jul 9 14:50:34] DEBUG[9104] chan_sip.c: SIP call-id changed from '315399090ed08f106ddaa11563ae5688@127.0.0.1:5060' to '634fb7e229b9a605053954113ad5fe41@192.168.1.146:5060' [Jul 9 14:50:34] DEBUG[9104] chan_sip.c: Initializing initreq for method OPTIONS - callid 634fb7e229b9a605053954113ad5fe41@192.168.1.146:5060 [Jul 9 14:50:34] DEBUG[9104] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.1.143:5080 [Jul 9 14:50:34] DEBUG[9104] chan_sip.c: = Looking for Call ID: 634fb7e229b9a605053954113ad5fe41@192.168.1.146:5060 (Checking To) --From tag as63f7aad2 --To-tag ZQ3mU250H3BSp [Jul 9 14:50:34] DEBUG[9104] chan_sip.c: Stopping retransmission on '634fb7e229b9a605053954113ad5fe41@192.168.1.146:5060' of Request 102: Match Found [Jul 9 14:50:34] DEBUG[9104] chan_sip.c: Destroying SIP dialog 634fb7e229b9a605053954113ad5fe41@192.168.1.146:5060 [Jul 9 14:51:09] Asterisk 13.4.0 built by root @ asterisk-1 on a x86_64 running Linux on 2015-07-03 11:06:05 UTC [Jul 9 14:51:22] Asterisk 13.4.0 built by root @ asterisk-1 on a x86_64 running Linux on 2015-07-03 11:06:05 UTC [Jul 9 14:52:22] Asterisk 13.4.0 built by root @ asterisk-1 on a x86_64 running Linux on 2015-07-03 11:06:05 UTC [Jul 9 14:52:34] DEBUG[12040] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 9 14:52:34] DEBUG[9049] threadpool.c: Destroying worker thread 137 [Jul 9 14:52:34] DEBUG[9104] chan_sip.c: Allocating new SIP dialog for 2ae1cf145a7dcb263c9716eb1a911c76@127.0.0.1:5060 - OPTIONS (No RTP) [Jul 9 14:52:34] DEBUG[9104] acl.c: For destination '192.168.1.143', our source address is '192.168.1.146'. [Jul 9 14:52:34] DEBUG[9104] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.1.146:5060 [Jul 9 14:52:34] DEBUG[9104] chan_sip.c: SIP call-id changed from '2ae1cf145a7dcb263c9716eb1a911c76@127.0.0.1:5060' to '51dbeea36434dcb675b7905223de08ad@192.168.1.146:5060' [Jul 9 14:52:34] DEBUG[9104] chan_sip.c: Initializing initreq for method OPTIONS - callid 51dbeea36434dcb675b7905223de08ad@192.168.1.146:5060 [Jul 9 14:52:34] DEBUG[9104] chan_sip.c: Trying to put 'OPTIONS sip' onto UDP socket destined for 192.168.1.143:5080 [Jul 9 14:52:34] DEBUG[9104] chan_sip.c: = Looking for Call ID: 51dbeea36434dcb675b7905223de08ad@192.168.1.146:5060 (Checking To) --From tag as63ec16f1 --To-tag 19N6yr77BNryD [Jul 9 14:52:34] DEBUG[9104] chan_sip.c: Stopping retransmission on '51dbeea36434dcb675b7905223de08ad@192.168.1.146:5060' of Request 102: Match Found [Jul 9 14:52:34] DEBUG[9104] chan_sip.c: Destroying SIP dialog 51dbeea36434dcb675b7905223de08ad@192.168.1.146:5060 [Jul 9 14:52:50] Asterisk 13.4.0 built by root @ asterisk-1 on a x86_64 running Linux on 2015-07-03 11:06:05 UTC [Jul 9 14:52:55] DEBUG[9104] chan_sip.c: = Looking for Call ID: 76590Njc3ODUyMTEwY2UyNTRkOTQwNzAxNTk1MGE0NjllNzQ (Checking From) --From tag d098227d --To-tag [Jul 9 14:52:55] DEBUG[9104] acl.c: For destination '192.168.1.199', our source address is '192.168.1.146'. [Jul 9 14:52:55] DEBUG[9104] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.1.146:5060 [Jul 9 14:52:55] DEBUG[9104] netsock2.c: Splitting '192.168.1.199:55180' into... [Jul 9 14:52:55] DEBUG[9104] netsock2.c: ...host '192.168.1.199' and port '55180'. [Jul 9 14:52:55] DEBUG[9104] chan_sip.c: Allocating new SIP dialog for 76590Njc3ODUyMTEwY2UyNTRkOTQwNzAxNTk1MGE0NjllNzQ - INVITE (No RTP) [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.1.199:55180' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.1.199' and port '55180'. [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.1.146:5060' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.1.146' and port ''. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 192.168.1.199:55180 [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_config_mysql.c: MySQL RealTime: Connection okay. [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers WHERE name = '1001' AND host = 'dynamic' [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_config_mysql.c: MySQL RealTime: Connection okay. [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers WHERE name = '1001' [Jul 9 14:52:55] DEBUG[9104] chan_sip.c: = Looking for Call ID: 76590Njc3ODUyMTEwY2UyNTRkOTQwNzAxNTk1MGE0NjllNzQ (Checking From) --From tag d098227d --To-tag as00aecc78 [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Stopping retransmission on '76590Njc3ODUyMTEwY2UyNTRkOTQwNzAxNTk1MGE0NjllNzQ' of Response 1: Match Found [Jul 9 14:52:55] DEBUG[9104] chan_sip.c: = Looking for Call ID: 76590Njc3ODUyMTEwY2UyNTRkOTQwNzAxNTk1MGE0NjllNzQ (Checking From) --From tag d098227d --To-tag [Jul 9 14:52:55] DEBUG[9104] netsock2.c: Splitting '192.168.1.146:5060' into... [Jul 9 14:52:55] DEBUG[9104] netsock2.c: ...host '192.168.1.146' and port '5060'. [Jul 9 14:52:55] DEBUG[9104] netsock2.c: Splitting '192.168.1.146:5060' into... [Jul 9 14:52:55] DEBUG[9104] netsock2.c: ...host '192.168.1.146' and port '5060'. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.1.199:55180' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.1.199' and port '55180'. [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.1.146:5060' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.1.146' and port ''. [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f1ce400e908' [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_rtp_asterisk.c: Allocated port 19958 for RTP instance '0x7f1ce400e908' [Jul 9 14:52:55] DEBUG[9104][C-00000008] pjsip: icess0x7f1ce40 ICE session created, comp_cnt=2, role is Unknown agent [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.1.146' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.1.146' and port ''. [Jul 9 14:52:55] DEBUG[9104][C-00000008] pjsip: icess0x7f1ce40 Candidate 0 added: comp_id=1, type=host, foundation=Hc0a80192, addr=192.168.1.146:19958, base=192.168.1.146:19958, prio=0x7effffff (2130706431) [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.122.1' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.122.1' and port ''. [Jul 9 14:52:55] DEBUG[9104][C-00000008] pjsip: icess0x7f1ce40 Candidate 1 added: comp_id=1, type=host, foundation=Hc0a87a01, addr=192.168.122.1:19958, base=192.168.122.1:19958, prio=0x7effffff (2130706431) [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: RTP instance '0x7f1ce400e908' is setup and ready to go [Jul 9 14:52:55] DEBUG[9104][C-00000008] pjsip: icess0x7f1ce40 Destroying ICE session 0x7f1ce4012188 [Jul 9 14:52:55] DEBUG[9104][C-00000008] pjsip: stuse0x7f1ce40 STUN session 0x7f1ce40145a8 destroy request, ref_cnt=4 [Jul 9 14:52:55] DEBUG[9104][C-00000008] pjsip: stuse0x7f1ce40 STUN session 0x7f1ce40155a8 destroy request, ref_cnt=3 [Jul 9 14:52:55] DEBUG[9104][C-00000008] pjsip: ice_session.c ICE session 0x7f1ce4012188 destroyed [Jul 9 14:52:55] DEBUG[9104][C-00000008] pjsip: stun_session.c STUN session 0x7f1ce40145a8 destroyed [Jul 9 14:52:55] DEBUG[9104][C-00000008] pjsip: stun_session.c STUN session 0x7f1ce40155a8 destroyed [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f1ce400e908' [Jul 9 14:52:55] VERBOSE[9104][C-00000008] netsock2.c: Using SIP RTP TOS bits 184 [Jul 9 14:52:55] VERBOSE[9104][C-00000008] netsock2.c: Using SIP RTP CoS mark 5 [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Setting NAT on RTP to Off [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing session-level SDP o=- 1436442775609243 1 IN IP4 192.168.1.199... OK. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing session-level SDP s=X-Lite release 4.8.4 stamp 76590... UNSUPPORTED OR FAILED. [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.1.199' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.1.199' and port ''. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.1.199... OK. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Setting payload 9 (0x7f1ce4007038) based on m type on 0x7f1ca85f92d0 [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Setting payload 8 (0x7f1ce4019ee8) based on m type on 0x7f1ca85f92d0 [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Setting payload 0 (0x7f1ce401a348) based on m type on 0x7f1ca85f92d0 [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Setting payload 101 (0x7f1ce401a7a8) based on m type on 0x7f1ca85f92d0 [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f1ce400e908' [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Copying payload 0 (0x7f1ce401a348) from 0x7f1ca85f92d0 to 0x7f1ce400ead0 [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Copying payload 8 (0x7f1ce4019ee8) from 0x7f1ca85f92d0 to 0x7f1ce400ead0 [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Copying payload 9 (0x7f1ce4007038) from 0x7f1ca85f92d0 to 0x7f1ce400ead0 [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Copying payload 101 (0x7f1ce401ac08) from 0x7f1ca85f92d0 to 0x7f1ce400ead0 [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f1ce400e908' [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: We're settling with these formats: (ulaw|alaw) [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Checking SIP call limits for device 111 [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Updating call counter for incoming call [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.1.146:5060' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.1.146' and port ''. [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.1.146:5060' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.1.146' and port ''. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: *** Our native formats are (ulaw) [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: *** Joint capabilities are (ulaw|alaw) [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: *** Our capabilities are (ulaw|alaw|gsm|h263) [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: This channel will not be able to handle video. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: SIP/111-0000000d: New call is still down.... Trying... [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 192.168.1.199:55180 [Jul 9 14:52:55] DEBUG[9056] devicestate.c: No provider found, checking channel drivers for SIP - 111 [Jul 9 14:52:55] DEBUG[9056] chan_sip.c: Checking device state for peer 111 [Jul 9 14:52:55] DEBUG[9056] devicestate.c: Changing state for SIP/111 - state 2 (In use) [Jul 9 14:52:55] DEBUG[9056] devicestate.c: No provider found, checking channel drivers for SIP - 111 [Jul 9 14:52:55] DEBUG[9056] chan_sip.c: Checking device state for peer 111 [Jul 9 14:52:55] DEBUG[9056] devicestate.c: Changing state for SIP/111 - state 2 (In use) [Jul 9 14:52:55] DEBUG[9049] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 9 14:52:55] DEBUG[9063] app_queue.c: Extension '111@subscribe' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jul 9 14:52:55] DEBUG[9120] app_queue.c: Device 'SIP/111' changed to state '2' (In use) [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_config_mysql.c: MySQL RealTime: Connection okay. [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers WHERE name = '1001' AND host = 'dynamic' [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_config_mysql.c: MySQL RealTime: Connection okay. [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_config_mysql.c: MySQL RealTime: Retrieve SQL: SELECT * FROM sippeers WHERE name = '1001' [Jul 9 14:52:55] DEBUG[12050][C-00000008] pbx.c: Result of 'EXTEN' is '1001' [Jul 9 14:52:55] DEBUG[12050][C-00000008] pbx.c: Launching 'Dial' [Jul 9 14:52:55] VERBOSE[12050][C-00000008] pbx.c: Executing [1001@home:1] Dial("SIP/111-0000000d", "SIP/freesw/1001") in new stack [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Asked to create a SIP channel with formats: (ulaw) [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Allocating new SIP dialog for 06ad9b941d11f78f3401c52a0c93908d@127.0.0.1:5060 - INVITE (No RTP) [Jul 9 14:52:55] DEBUG[12050][C-00000008] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f1ceaa94c48' [Jul 9 14:52:55] DEBUG[12050][C-00000008] res_rtp_asterisk.c: Allocated port 18636 for RTP instance '0x7f1ceaa94c48' [Jul 9 14:52:55] DEBUG[12050][C-00000008] pjsip: icess0x7f1ceaf ICE session created, comp_cnt=2, role is Unknown agent [Jul 9 14:52:55] DEBUG[12050][C-00000008] netsock2.c: Splitting '192.168.1.146' into... [Jul 9 14:52:55] DEBUG[12050][C-00000008] netsock2.c: ...host '192.168.1.146' and port ''. [Jul 9 14:52:55] DEBUG[12050][C-00000008] pjsip: icess0x7f1ceaf Candidate 0 added: comp_id=1, type=host, foundation=Hc0a80192, addr=192.168.1.146:18636, base=192.168.1.146:18636, prio=0x7effffff (2130706431) [Jul 9 14:52:55] DEBUG[12050][C-00000008] netsock2.c: Splitting '192.168.122.1' into... [Jul 9 14:52:55] DEBUG[12050][C-00000008] netsock2.c: ...host '192.168.122.1' and port ''. [Jul 9 14:52:55] DEBUG[12050][C-00000008] pjsip: icess0x7f1ceaf Candidate 1 added: comp_id=1, type=host, foundation=Hc0a87a01, addr=192.168.122.1:18636, base=192.168.122.1:18636, prio=0x7effffff (2130706431) [Jul 9 14:52:55] DEBUG[12050][C-00000008] rtp_engine.c: RTP instance '0x7f1ceaa94c48' is setup and ready to go [Jul 9 14:52:55] DEBUG[12050][C-00000008] pjsip: icess0x7f1ceaf Destroying ICE session 0x7f1ceafb4048 [Jul 9 14:52:55] DEBUG[12050][C-00000008] pjsip: stuse0x7f1ce9a STUN session 0x7f1ce9239958 destroy request, ref_cnt=4 [Jul 9 14:52:55] DEBUG[12050][C-00000008] pjsip: stuse0x7f1cea5 STUN session 0x7f1ca0c35b38 destroy request, ref_cnt=3 [Jul 9 14:52:55] DEBUG[12050][C-00000008] pjsip: ice_session.c ICE session 0x7f1ceafb4048 destroyed [Jul 9 14:52:55] DEBUG[12050][C-00000008] pjsip: stun_session.c STUN session 0x7f1ce9239958 destroyed [Jul 9 14:52:55] DEBUG[12050][C-00000008] pjsip: stun_session.c STUN session 0x7f1ca0c35b38 destroyed [Jul 9 14:52:55] DEBUG[12050][C-00000008] res_rtp_asterisk.c: Setup RTCP on RTP instance '0x7f1ceaa94c48' [Jul 9 14:52:55] VERBOSE[12050][C-00000008] netsock2.c: Using SIP RTP TOS bits 184 [Jul 9 14:52:55] VERBOSE[12050][C-00000008] netsock2.c: Using SIP RTP CoS mark 5 [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Setting NAT on RTP to Off [Jul 9 14:52:55] DEBUG[12050][C-00000008] acl.c: For destination '192.168.1.143', our source address is '192.168.1.146'. [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Setting AST_TRANSPORT_UDP with address 192.168.1.146:5060 [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Setting NAT on RTP to Off [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: SIP call-id changed from '06ad9b941d11f78f3401c52a0c93908d@127.0.0.1:5060' to '1562da5d0c5c4a0c3f6d655a7a7c1e31@192.168.1.146:5060' [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: *** Our native formats are (ulaw) [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: *** Joint capabilities are (ulaw) [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: *** Our capabilities are (alaw|ulaw|g722) [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: *** AST_CODEC_CHOOSE formats are ulaw [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: *** Our preferred formats from the incoming channel are (ulaw) [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: This channel will not be able to handle video. [Jul 9 14:52:55] DEBUG[12050][C-00000008] channel_internal_api.c: Channel Call ID changing from [C-00000008] to [C-00000008] [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Outgoing Call for 1001 [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Updating call counter for outgoing call [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: ** Our capability: (ulaw|alaw|g722) Video flag: False Text flag: False [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: ** Our prefcodec: (ulaw) [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: -- Done with adding codecs to SDP [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw|g722) [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Initializing initreq for method INVITE - callid 1562da5d0c5c4a0c3f6d655a7a7c1e31@192.168.1.146:5060 [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 192.168.1.143:5080 [Jul 9 14:52:55] VERBOSE[12050][C-00000008] app_dial.c: Called SIP/freesw/1001 [Jul 9 14:52:55] DEBUG[9049] threadpool.c: Increasing threadpool stasis-core's size by 1 [Jul 9 14:52:55] DEBUG[9104] chan_sip.c: = Looking for Call ID: 1562da5d0c5c4a0c3f6d655a7a7c1e31@192.168.1.146:5060 (Checking To) --From tag as11c38464 --To-tag [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '1562da5d0c5c4a0c3f6d655a7a7c1e31@192.168.1.146:5060' Request 102: Found [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: SIP response 100 to standard invite [Jul 9 14:52:55] DEBUG[9056] devicestate.c: No provider found, checking channel drivers for SIP - freesw [Jul 9 14:52:55] DEBUG[9056] chan_sip.c: Checking device state for peer freesw [Jul 9 14:52:55] DEBUG[9056] devicestate.c: Changing state for SIP/freesw - state 6 (Ringing) [Jul 9 14:52:55] DEBUG[9120] app_queue.c: Device 'SIP/freesw' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Jul 9 14:52:55] DEBUG[9104] chan_sip.c: = Looking for Call ID: 1562da5d0c5c4a0c3f6d655a7a7c1e31@192.168.1.146:5060 (Checking To) --From tag as11c38464 --To-tag 2jFZ0KrB9XeHS [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Acked pending invite 102 [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Stopping retransmission on '1562da5d0c5c4a0c3f6d655a7a7c1e31@192.168.1.146:5060' of Request 102: Match Found [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: SIP response 200 to standard invite [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing session-level SDP o=FreeSWITCH 1436269524 1436269525 IN IP4 192.168.1.143... OK. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing session-level SDP s=FreeSWITCH... UNSUPPORTED OR FAILED. [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.1.143' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.1.143' and port ''. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing session-level SDP c=IN IP4 192.168.1.143... OK. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Setting payload 0 (0x7f1ce400e4a8) based on m type on 0x7f1ca85f8950 [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Setting payload 101 (0x7f1ce40196d8) based on m type on 0x7f1ca85f8950 [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED OR FAILED. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0x7f1ceaa94c48' [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Copying payload 0 (0x7f1ce4003148) from 0x7f1ca85f8950 to 0x7f1ceaa94e10 [Jul 9 14:52:55] DEBUG[9104][C-00000008] rtp_engine.c: Copying payload 101 (0x7f1ce400e4a8) from 0x7f1ca85f8950 to 0x7f1ceaa94e10 [Jul 9 14:52:55] DEBUG[9104][C-00000008] res_rtp_asterisk.c: Ignoring duplicate RTCP property on RTP instance '0x7f1ceaa94c48' [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: We're settling with these formats: (ulaw) [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: We have an owner, now see if we need to change this call [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Updating call counter for outgoing call [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.1.143:5080' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.1.143' and port '5080'. [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: Splitting '192.168.1.143:5080' into... [Jul 9 14:52:55] DEBUG[9104][C-00000008] netsock2.c: ...host '192.168.1.143' and port '5080'. [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Trying to put 'ACK sip:100' onto UDP socket destined for 192.168.1.143:5080 [Jul 9 14:52:55] VERBOSE[12050][C-00000008] app_dial.c: SIP/freesw-0000000e answered SIP/111-0000000d [Jul 9 14:52:55] DEBUG[12050][C-00000008] rtp_engine.c: Setting early bridge SDP of 'SIP/111-0000000d' with that of 'SIP/freesw-0000000e' [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: SIP answering channel: SIP/111-0000000d [Jul 9 14:52:55] DEBUG[12050][C-00000008] res_rtp_asterisk.c: Setting the marker bit due to a source update [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Setting framing from config on incoming call [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: ** Our capability: (ulaw|alaw) Video flag: True Text flag: True [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: ** Our prefcodec: (nothing) [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: -- Done with adding codecs to SDP [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Done building SDP. Settling with this capability: (ulaw|alaw) [Jul 9 14:52:55] DEBUG[12050][C-00000008] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.1.199:55180 [Jul 9 14:52:55] DEBUG[12050][C-00000008] dahdi/bridge_native_dahdi.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: Cannot use native DAHDI. Must have two channels. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge_native_rtp.c: Bridge '3c2839a4-bf56-4c98-9c7f-95ec7a09c74d' can not use native RTP bridge as two channels are required [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Chose bridge technology simple_bridge [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: calling simple_bridge technology constructor [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: calling simple_bridge technology start [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge_channel.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: 0x7f1c9ccfdc08(SIP/111-0000000d) is joining [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge_channel.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: pushing 0x7f1c9ccfdc08(SIP/111-0000000d) [Jul 9 14:52:55] VERBOSE[12050][C-00000008] bridge_channel.c: Channel SIP/111-0000000d joined 'simple_bridge' basic-bridge <3c2839a4-bf56-4c98-9c7f-95ec7a09c74d> [Jul 9 14:52:55] DEBUG[12050][C-00000008] dahdi/bridge_native_dahdi.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: Cannot use native DAHDI. Must have two channels. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge_native_rtp.c: Bridge '3c2839a4-bf56-4c98-9c7f-95ec7a09c74d' can not use native RTP bridge as two channels are required [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Chose bridge technology simple_bridge [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d is already using the new technology. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: 0x7f1c9ccfdc08(SIP/111-0000000d) is joining simple_bridge technology [Jul 9 14:52:55] DEBUG[12050][C-00000008] res_rtp_asterisk.c: Not changing SSRC since we haven't sent any RTP yet [Jul 9 14:52:55] DEBUG[9056] devicestate.c: No provider found, checking channel drivers for SIP - freesw [Jul 9 14:52:55] DEBUG[9056] chan_sip.c: Checking device state for peer freesw [Jul 9 14:52:55] DEBUG[9056] devicestate.c: Changing state for SIP/freesw - state 2 (In use) [Jul 9 14:52:55] DEBUG[9056] devicestate.c: No provider found, checking channel drivers for SIP - freesw [Jul 9 14:52:55] DEBUG[9056] chan_sip.c: Checking device state for peer freesw [Jul 9 14:52:55] DEBUG[9056] devicestate.c: Changing state for SIP/freesw - state 2 (In use) [Jul 9 14:52:55] DEBUG[9056] devicestate.c: No provider found, checking channel drivers for SIP - 111 [Jul 9 14:52:55] DEBUG[9056] chan_sip.c: Checking device state for peer 111 [Jul 9 14:52:55] DEBUG[9056] devicestate.c: Changing state for SIP/111 - state 2 (In use) [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge_channel.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: 0x7f1cebed8de8(SIP/freesw-0000000e) is joining [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge_channel.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: pushing 0x7f1cebed8de8(SIP/freesw-0000000e) [Jul 9 14:52:55] VERBOSE[12053][C-00000008] bridge_channel.c: Channel SIP/freesw-0000000e joined 'simple_bridge' basic-bridge <3c2839a4-bf56-4c98-9c7f-95ec7a09c74d> [Jul 9 14:52:55] DEBUG[12053][C-00000008] dahdi/bridge_native_dahdi.c: Channel 'SIP/111-0000000d' is not DAHDI. [Jul 9 14:52:55] DEBUG[12053][C-00000008] dahdi/bridge_native_dahdi.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: Cannot use native DAHDI. Channel 'SIP/111-0000000d' not compatible. [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Chose bridge technology native_rtp [Jul 9 14:52:55] VERBOSE[12053][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: switching from simple_bridge technology to native_rtp [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: calling native_rtp technology constructor [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: moving 0x7f1c9ccfdc08(SIP/111-0000000d) to dummy bridge temporarily [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: 0x7f1c9ccfdc08(SIP/111-0000000d) is leaving simple_bridge technology (dummy) [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: calling simple_bridge technology stop [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: 0x7f1cebed8de8(SIP/freesw-0000000e) is joining native_rtp technology [Jul 9 14:52:55] VERBOSE[12053][C-00000008] bridge_native_rtp.c: Locally RTP bridged 'SIP/freesw-0000000e' and 'SIP/111-0000000d' in stack [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: 0x7f1c9ccfdc08(SIP/111-0000000d) is joining native_rtp technology [Jul 9 14:52:55] VERBOSE[12053][C-00000008] bridge_native_rtp.c: Locally RTP bridged 'SIP/freesw-0000000e' and 'SIP/111-0000000d' in stack [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: calling native_rtp technology start [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: calling simple_bridge technology destructor [Jul 9 14:52:55] DEBUG[12053][C-00000008] res_rtp_asterisk.c: Not changing SSRC since we haven't sent any RTP yet [Jul 9 14:52:55] DEBUG[12053][C-00000008] dahdi/bridge_native_dahdi.c: Channel 'SIP/freesw-0000000e' is not DAHDI. [Jul 9 14:52:55] DEBUG[12053][C-00000008] dahdi/bridge_native_dahdi.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: Cannot use native DAHDI. Channel 'SIP/freesw-0000000e' not compatible. [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Chose bridge technology native_rtp [Jul 9 14:52:55] DEBUG[12053][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d is already using the new technology. [Jul 9 14:52:55] DEBUG[9120] app_queue.c: Device 'SIP/freesw' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jul 9 14:52:55] DEBUG[9062] cdr.c: Finalized CDR for SIP/freesw-0000000e - start 1436442775.732067 answer 1436442775.750255 end 1436442775.753574 dispo ANSWERED [Jul 9 14:52:55] DEBUG[12050][C-00000008] dahdi/bridge_native_dahdi.c: Channel 'SIP/freesw-0000000e' is not DAHDI. [Jul 9 14:52:55] DEBUG[12050][C-00000008] dahdi/bridge_native_dahdi.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d: Cannot use native DAHDI. Channel 'SIP/freesw-0000000e' not compatible. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge technology native_dahdi is not compatible with properties of existing bridge. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge technology softmix does not have any capabilities we want. [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Chose bridge technology native_rtp [Jul 9 14:52:55] DEBUG[12050][C-00000008] bridge.c: Bridge 3c2839a4-bf56-4c98-9c7f-95ec7a09c74d is already using the new technology. [Jul 9 14:52:55] DEBUG[9104] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 200 ms (t1 100 ms (Retrans id #334)) [Jul 9 14:52:55] DEBUG[9104] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 192.168.1.199:55180 [Jul 9 14:52:55] DEBUG[9104] chan_sip.c: = Looking for Call ID: 76590Njc3ODUyMTEwY2UyNTRkOTQwNzAxNTk1MGE0NjllNzQ (Checking From) --From tag d098227d --To-tag as61d35fd8 [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: Stopping retransmission on '76590Njc3ODUyMTEwY2UyNTRkOTQwNzAxNTk1MGE0NjllNzQ' of Response 2: Match Found [Jul 9 14:52:55] DEBUG[12050][C-00000008] res_rtp_asterisk.c: 0x7f1ce4007ea0 -- Probation learning mode pass with source address 192.168.1.199:63912 [Jul 9 14:52:55] VERBOSE[12050][C-00000008] res_rtp_asterisk.c: 0x7f1ce4007ea0 -- Probation passed - setting RTP source address to 192.168.1.199:63912 [Jul 9 14:52:55] DEBUG[12050][C-00000008] res_rtp_asterisk.c: Got RTCP report of 56 bytes [Jul 9 14:52:55] DEBUG[12050][C-00000008] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 9 14:52:55] DEBUG[12050][C-00000008] netsock2.c: Splitting 'asterisk-1' into... [Jul 9 14:52:55] DEBUG[12050][C-00000008] netsock2.c: ...host 'asterisk-1' and port ''. [Jul 9 14:52:55] DEBUG[12050][C-00000008] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 9 14:52:55] DEBUG[12050][C-00000008] acl.c: Attached to given IP address [Jul 9 14:52:55] DEBUG[9114] netsock2.c: Splitting '192.168.1.199:63913' into... [Jul 9 14:52:55] DEBUG[9114] netsock2.c: ...host '192.168.1.199' and port '63913'. [Jul 9 14:52:55] DEBUG[9114] netsock2.c: Splitting '127.0.0.1:0' into... [Jul 9 14:52:55] DEBUG[9114] netsock2.c: ...host '127.0.0.1' and port '0'. [Jul 9 14:52:55] DEBUG[9104] chan_sip.c: = Looking for Call ID: 76590Njc3ODUyMTEwY2UyNTRkOTQwNzAxNTk1MGE0NjllNzQ (Checking From) --From tag d098227d --To-tag as61d35fd8 [Jul 9 14:52:55] DEBUG[9104][C-00000008] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Jul 9 14:52:56] DEBUG[12053][C-00000008] res_rtp_asterisk.c: 0x7f1ce9a95d40 -- Probation learning mode pass with source address 192.168.1.143:28600 [Jul 9 14:52:56] VERBOSE[12053][C-00000008] res_rtp_asterisk.c: 0x7f1ce9a95d40 -- Probation passed - setting RTP source address to 192.168.1.143:28600 [Jul 9 14:53:02] DEBUG[12050][C-00000008] res_rtp_asterisk.c: Got RTCP report of 80 bytes [Jul 9 14:53:02] DEBUG[12050][C-00000008] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 9 14:53:02] DEBUG[12050][C-00000008] netsock2.c: Splitting 'asterisk-1' into... [Jul 9 14:53:02] DEBUG[12050][C-00000008] netsock2.c: ...host 'asterisk-1' and port ''. [Jul 9 14:53:02] DEBUG[12050][C-00000008] acl.c: Not an IPv4 nor IPv6 address, cannot get port. [Jul 9 14:53:02] DEBUG[12050][C-00000008] acl.c: Attached to given IP address [Jul 9 14:53:02] DEBUG[9114] netsock2.c: Splitting '192.168.1.199:63913' into... [Jul 9 14:53:02] DEBUG[9114] netsock2.c: ...host '192.168.1.199' and port '63913'. [Jul 9 14:53:02] DEBUG[9114] netsock2.c: Splitting '127.0.0.1:0' into... [Jul 9 14:53:02] DEBUG[9114] netsock2.c: ...host '127.0.0.1' and port '0'. [Jul 9 14:53:04] DEBUG[12038] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 9 14:53:04] DEBUG[12039] threadpool.c: Worker thread idle timeout reached. Dying. [Jul 9 14:53:04] DEBUG[9068] threadpool.c: Destroying worker thread 135 [Jul 9 14:53:04] DEBUG[9068] threadpool.c: Destroying worker thread 136