[asterisk-bugs] [JIRA] (ASTERISK-25229) Exchanging Device and Mailbox State Using PJSIP doesn't work correctly
Rusty Newton (JIRA)
noreply at issues.asterisk.org
Thu Jul 9 19:17:02 CDT 2015
[ https://issues.asterisk.org/jira/browse/ASTERISK-25229?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=226840#comment-226840 ]
Rusty Newton edited comment on ASTERISK-25229 at 7/9/15 7:13 PM:
-----------------------------------------------------------------
Asterisk 13.4.0 on both systems
A: 192.168.1.146
B: 192.168.1.148
On both: SIP-port: 5060, PJSIP-port: 5071
B - service asterisk restart
In the console of A: "[Jul 9 15:06:14] WARNING[14301]: res_pjsip_outbound_authenticator_digest.c:135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge.
[Jul 9 15:06:14] WARNING[14301]: res_pjsip_outbound_authenticator_digest.c:135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge."
Call through the server A (from 111 to 1001)
The console of B is empty! ('core set debug 5', 'pjsip set logger')
The debug_log of A is in the attached file.
>From B to A the exchange of the device state is correct.
Debug A:
[Edit by Rusty - Removed debug log as per the guidelines. Please follow the guidelines]
was (Author: cron333):
Asterisk 13.4.0 on both systems
A: 192.168.1.146
B: 192.168.1.148
On both: SIP-port: 5060, PJSIP-port: 5071
B - service asterisk restart
In the console of A: "[Jul 9 15:06:14] WARNING[14301]: res_pjsip_outbound_authenticator_digest.c:135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge.
[Jul 9 15:06:14] WARNING[14301]: res_pjsip_outbound_authenticator_digest.c:135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge."
Call through the server A (from 111 to 1001)
The console of B is empty! ('core set debug 5', 'pjsip set logger')
The debug_log of A is in the attached file.
>From B to A the exchange of the device state is correct.
Debug A:
[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 at 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 at 127.0.0.1:5060' to '184a7eb04c6ca05159580a7b23bda1b9 at 192.168.1.146:5060'
[Jul 9 14:50:04] DEBUG[9104] chan_sip.c: Initializing initreq for method OPTIONS - callid 184a7eb04c6ca05159580a7b23bda1b9 at 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 at 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 at 192.168.1.146:5060' of Request 102: Match Found
[Jul 9 14:50:04] DEBUG[9104] chan_sip.c: Destroying SIP dialog 184a7eb04c6ca05159580a7b23bda1b9 at 192.168.1.146:5060
[Jul 9 14:50:34] DEBUG[9104] chan_sip.c: Allocating new SIP dialog for 315399090ed08f106ddaa11563ae5688 at 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 at 127.0.0.1:5060' to '634fb7e229b9a605053954113ad5fe41 at 192.168.1.146:5060'
[Jul 9 14:50:34] DEBUG[9104] chan_sip.c: Initializing initreq for method OPTIONS - callid 634fb7e229b9a605053954113ad5fe41 at 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 at 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 at 192.168.1.146:5060' of Request 102: Match Found
[Jul 9 14:50:34] DEBUG[9104] chan_sip.c: Destroying SIP dialog 634fb7e229b9a605053954113ad5fe41 at 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 at 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 at 127.0.0.1:5060' to '51dbeea36434dcb675b7905223de08ad at 192.168.1.146:5060'
[Jul 9 14:52:34] DEBUG[9104] chan_sip.c: Initializing initreq for method OPTIONS - callid 51dbeea36434dcb675b7905223de08ad at 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 at 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 at 192.168.1.146:5060' of Request 102: Match Found
[Jul 9 14:52:34] DEBUG[9104] chan_sip.c: Destroying SIP dialog 51dbeea36434dcb675b7905223de08ad at 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 at 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 at 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 at 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 at 127.0.0.1:5060' to '1562da5d0c5c4a0c3f6d655a7a7c1e31 at 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 at 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 at 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 at 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 at 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 at 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
> Exchanging Device and Mailbox State Using PJSIP doesn't work correctly
> ----------------------------------------------------------------------
>
> Key: ASTERISK-25229
> URL: https://issues.asterisk.org/jira/browse/ASTERISK-25229
> Project: Asterisk
> Issue Type: Bug
> Security Level: None
> Affects Versions: 13.4.0
> Environment: CentOS-7 x86_64
> Reporter: Vadim
> Assignee: Unassigned
>
> There are two servers: "A" and "B".
> When we restart "Asterisk" on "A" we will see in the console of "B":
> [Jul 3 14:17:13] WARNING[17452]: res_pjsip_outbound_authenticator_digest.c:135 digest_create_request_with_auth_from_old: Unable to create request with auth.No auth credentials for any realms in challenge.
> After this "B' can't share a device state to "A", but "A" to "B" can.
> If we restart "Asterisk" on the server "B", the server "A" will not be able to share a device state to "B", but "B" to "A" can.
> The configuration, that has been used: https://wiki.asterisk.org/wiki/display/AST/Exchanging+Device+and+Mailbox+State+Using+PJSIP?showComments=true
--
This message was sent by Atlassian JIRA
(v6.2#6252)
More information about the asterisk-bugs
mailing list