[Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:8547 find_call: = Looking for Call ID: 24@10.3.25.10 (Checking From) --From tag 24417923471779367133 --To-tag [Sep 18 18:09:41] DEBUG[21544]: acl.c:736 ast_ouraddrfor: For destination '10.3.25.10', our source address is '10.1.0.19'. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:3839 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.1.0.19:5060 [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:8227 sip_alloc: Allocating new SIP dialog for 24@10.3.25.10 - INVITE (No RTP) [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:25870 handle_incoming: **** Received INVITE (5) - Command in SIP INVITE [Sep 18 18:09:41] DEBUG[21544]: sip/reqresp_parser.c:1603 parse_sip_options: Begin: parsing SIP "Supported: timer" [Sep 18 18:09:41] DEBUG[21544]: sip/reqresp_parser.c:1619 parse_sip_options: Found SIP option: -timer- [Sep 18 18:09:41] DEBUG[21544]: sip/reqresp_parser.c:1627 parse_sip_options: Matched SIP option: timer [Sep 18 18:09:41] DEBUG[21544]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '10.3.25.10:5060' into... [Sep 18 18:09:41] DEBUG[21544]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '10.3.25.10' and port '5060'. [Sep 18 18:09:41] DEBUG[21544]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '10.3.25.10:5060' into... [Sep 18 18:09:41] DEBUG[21544]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '10.3.25.10' and port ''. [Sep 18 18:09:41] DEBUG[21544]: rtp_engine.c:350 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x177ece8' [Sep 18 18:09:41] DEBUG[21544]: res_rtp_asterisk.c:558 ast_rtp_new: Allocated port 15658 for RTP instance '0x177ece8' [Sep 18 18:09:41] DEBUG[21544]: rtp_engine.c:359 ast_rtp_instance_new: RTP instance '0x177ece8' is setup and ready to go [Sep 18 18:09:41] DEBUG[21544]: res_rtp_asterisk.c:2543 ast_rtp_prop_set: Setup RTCP on RTP instance '0x177ece8' == Using SIP RTP CoS mark 5 [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:5474 do_setnat: Setting NAT on RTP to Off [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:9345 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:9345 process_sdp: Processing session-level SDP o=111 843670094 843670094 IN IP4 10.3.25.10... OK. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:9345 process_sdp: Processing session-level SDP s=-... UNSUPPORTED OR FAILED. [Sep 18 18:09:41] DEBUG[21544]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '10.3.25.10' into... [Sep 18 18:09:41] DEBUG[21544]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '10.3.25.10' and port ''. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:9345 process_sdp: Processing session-level SDP c=IN IP4 10.3.25.10... OK. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:9345 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:9345 process_sdp: Processing session-level SDP a=sendrecv... OK. [Sep 18 18:09:41] DEBUG[21544]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 8 based on m type on 0x7fa3d8bb7be0 [Sep 18 18:09:41] DEBUG[21544]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7fa3d8bb7be0 [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:9617 process_sdp: Processing media-level (audio) SDP a=rtpmap:0 PCMA/8000... OK. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:9617 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:9617 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:9617 process_sdp: Processing media-level (audio) SDP a=ptime:20... OK. [Sep 18 18:09:41] DEBUG[21544]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 0 on 0x7fa3d8bb7be0 [Sep 18 18:09:41] DEBUG[21544]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 8 on 0x7fa3d8bb7be0 [Sep 18 18:09:41] DEBUG[21544]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 101 on 0x7fa3d8bb7be0 [Sep 18 18:09:41] DEBUG[21544]: res_rtp_asterisk.c:2583 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x177ece8' [Sep 18 18:09:41] DEBUG[21544]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 0 from 0x7fa3d8bb7be0 to 0x177eeb0 [Sep 18 18:09:41] DEBUG[21544]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 8 from 0x7fa3d8bb7be0 to 0x177eeb0 [Sep 18 18:09:41] DEBUG[21544]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x7fa3d8bb7be0 to 0x177eeb0 [Sep 18 18:09:41] DEBUG[21544]: res_rtp_asterisk.c:2509 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x177ece8' [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:9871 process_sdp: We're settling with these formats: 0x8 (alaw) [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:23390 handle_request_invite: Checking SIP call limits for device [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:6300 update_call_counter: Updating call counter for incoming call [Sep 18 18:09:41] DEBUG[21544]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '10.1.0.19:5060' into... [Sep 18 18:09:41] DEBUG[21544]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '10.1.0.19' and port ''. [Sep 18 18:09:41] DEBUG[21544]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '10.3.25.10:5060' into... [Sep 18 18:09:41] DEBUG[21544]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '10.3.25.10' and port ''. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:7515 sip_new: *** Our native formats are 0x8 (alaw) [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:7516 sip_new: *** Joint capabilities are 0x8 (alaw) [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:7517 sip_new: *** Our capabilities are 0x8 (alaw) [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:7518 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:7548 sip_new: This channel will not be able to handle video. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:14850 build_route: build_route: Contact hop: [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:23505 handle_request_invite: Incoming INVITE with 'timer' option supported [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:23514 handle_request_invite: INVITE also has "Session-Expires" header. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:26871 parse_session_expires: Session-Expires: 90 [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:26884 parse_session_expires: Refresher: UAC [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:23531 handle_request_invite: INVITE also has "Min-SE" header. [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:26841 parse_minse: Received Min-SE: 90 [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:26755 start_session_timer: Session timer started: 1 - 24@10.3.25.10 60000ms [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:23696 handle_request_invite: SIP/infromclient-00000000: New call is still down.... Trying... [Sep 18 18:09:41] DEBUG[21544]: chan_sip.c:3687 __sip_xmit: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.3.25.10:5060 [Sep 18 18:09:41] DEBUG[21521]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - infromclient [Sep 18 18:09:41] DEBUG[21521]: chan_sip.c:27193 sip_devicestate: Checking device state for peer infromclient [Sep 18 18:09:41] DEBUG[21521]: devicestate.c:467 do_state_change: Changing state for SIP/infromclient - state 5 (Unavailable) [Sep 18 18:09:41] DEBUG[21521]: devicestate.c:442 devstate_event: device 'SIP/infromclient' state '5' [Sep 18 18:09:41] DEBUG[21554]: app_queue.c:1545 handle_statechange: Device 'SIP/infromclient' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Sep 18 18:09:41] DEBUG[21557]: pbx.c:4470 pbx_extension_helper: Launching 'Ringing' -- Executing [echo@default:1] Ringing("SIP/infromclient-00000000", "") in new stack [Sep 18 18:09:41] DEBUG[21557]: chan_sip.c:3687 __sip_xmit: Trying to put 'SIP/2.0 180' onto UDP socket destined for 10.3.25.10:5060 [Sep 18 18:09:41] DEBUG[21557]: pbx.c:4470 pbx_extension_helper: Launching 'Wait' -- Executing [echo@default:2] Wait("SIP/infromclient-00000000", "20") in new stack [Sep 18 18:10:01] DEBUG[21557]: pbx.c:3479 ast_str_retrieve_variable: Result of 'EXTEN' is 'echo' [Sep 18 18:10:01] DEBUG[21557]: pbx.c:4470 pbx_extension_helper: Launching 'Dial' -- Executing [echo@default:3] Dial("SIP/infromclient-00000000", "SIP/echo@outtotest") in new stack [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:27297 sip_request_call: Asked to create a SIP channel with formats: 0x8 (alaw) [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:8227 sip_alloc: Allocating new SIP dialog for 600c031d1928491d0f73175748472a93@10.1.0.19:5060 - INVITE (No RTP) [Sep 18 18:10:01] DEBUG[21557]: rtp_engine.c:350 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7fa3f4005c78' [Sep 18 18:10:01] DEBUG[21557]: res_rtp_asterisk.c:558 ast_rtp_new: Allocated port 18628 for RTP instance '0x7fa3f4005c78' [Sep 18 18:10:01] DEBUG[21557]: rtp_engine.c:359 ast_rtp_instance_new: RTP instance '0x7fa3f4005c78' is setup and ready to go [Sep 18 18:10:01] DEBUG[21557]: res_rtp_asterisk.c:2543 ast_rtp_prop_set: Setup RTCP on RTP instance '0x7fa3f4005c78' == Using SIP RTP CoS mark 5 [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:5474 do_setnat: Setting NAT on RTP to Off [Sep 18 18:10:01] DEBUG[21557]: acl.c:736 ast_ouraddrfor: For destination '212.79.111.155', our source address is '10.1.0.19'. [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:3839 ast_sip_ouraddrfor: Setting SIP_TRANSPORT_UDP with address 10.1.0.19:5060 [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:8053 change_callid_pvt: SIP call-id changed from '600c031d1928491d0f73175748472a93@10.1.0.19:5060' to '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:7515 sip_new: *** Our native formats are 0x8 (alaw) [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:7516 sip_new: *** Joint capabilities are 0x8 (alaw) [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:7517 sip_new: *** Our capabilities are 0x8 (alaw) [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:7518 sip_new: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:7520 sip_new: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:7548 sip_new: This channel will not be able to handle video. [Sep 18 18:10:01] DEBUG[21557]: rtp_engine.c:1494 ast_rtp_instance_early_bridge_make_compatible: Seeded SDP of 'SIP/outtotest-00000001' with that of 'SIP/infromclient-00000000' [Sep 18 18:10:01] DEBUG[21557]: channel.c:6232 ast_channel_inherit_variables: Not copying variable DIALEDTIME. [Sep 18 18:10:01] DEBUG[21557]: channel.c:6232 ast_channel_inherit_variables: Not copying variable ANSWEREDTIME. [Sep 18 18:10:01] DEBUG[21557]: channel.c:6232 ast_channel_inherit_variables: Not copying variable DIALEDPEERNAME. [Sep 18 18:10:01] DEBUG[21557]: channel.c:6232 ast_channel_inherit_variables: Not copying variable DIALEDPEERNUMBER. [Sep 18 18:10:01] DEBUG[21557]: channel.c:6232 ast_channel_inherit_variables: Not copying variable DIALSTATUS. [Sep 18 18:10:01] DEBUG[21557]: channel.c:6232 ast_channel_inherit_variables: Not copying variable SIPCALLID. [Sep 18 18:10:01] DEBUG[21557]: channel.c:6232 ast_channel_inherit_variables: Not copying variable SIPDOMAIN. [Sep 18 18:10:01] DEBUG[21557]: channel.c:6232 ast_channel_inherit_variables: Not copying variable SIPURI. [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:6017 sip_call: Outgoing Call for echo [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:6300 update_call_counter: Updating call counter for outgoing call [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:11884 add_sdp: ** Our capability: 0x8 (alaw) Video flag: False Text flag: False [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:11885 add_sdp: ** Our prefcodec: 0x8 (alaw) [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:11994 add_sdp: -- Done with adding codecs to SDP [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:12180 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:3363 initialize_initreq: Initializing initreq for method INVITE - callid 659653691ee49fc173fd87150ca8f446@10.1.0.19:5060 [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:3687 __sip_xmit: Trying to put 'INVITE sip:' onto UDP socket destined for 212.79.111.155:5060 -- Called SIP/echo@outtotest [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:8547 find_call: = Looking for Call ID: 659653691ee49fc173fd87150ca8f446@10.1.0.19:5060 (Checking To) --From tag as1672d8e0 --To-tag [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:4412 __sip_semi_ack: (Provisional) Stopping retransmission (but retaining packet) on '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Request 102: Found [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:20713 handle_response_invite: SIP response 100 to standard invite [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:8547 find_call: = Looking for Call ID: 659653691ee49fc173fd87150ca8f446@10.1.0.19:5060 (Checking To) --From tag as1672d8e0 --To-tag 08B58658-5239D05900013367-EC64A700 [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:4333 __sip_ack: Acked pending invite 102 [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:4371 __sip_ack: Stopping retransmission on '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' of Request 102: Match Found [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:20713 handle_response_invite: SIP response 200 to standard invite [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9345 process_sdp: Processing session-level SDP v=0... UNSUPPORTED OR FAILED. [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9345 process_sdp: Processing session-level SDP o=- 88702433 697236295 IN IP4 212.79.111.155... OK. [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9345 process_sdp: Processing session-level SDP s=-... UNSUPPORTED OR FAILED. [Sep 18 18:10:01] DEBUG[21544]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '212.79.111.155' into... [Sep 18 18:10:01] DEBUG[21544]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '212.79.111.155' and port ''. [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9345 process_sdp: Processing session-level SDP c=IN IP4 212.79.111.155... OK. [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9345 process_sdp: Processing session-level SDP t=0 0... UNSUPPORTED OR FAILED. [Sep 18 18:10:01] DEBUG[21544]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 8 based on m type on 0x7fa3d8bb7290 [Sep 18 18:10:01] DEBUG[21544]: rtp_engine.c:541 ast_rtp_codecs_payloads_set_m_type: Setting payload 101 based on m type on 0x7fa3d8bb7290 [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9617 process_sdp: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9617 process_sdp: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9617 process_sdp: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED OR FAILED. [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9617 process_sdp: Processing media-level (audio) SDP a=sendrecv... OK. [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9617 process_sdp: Processing media-level (audio) SDP a=direction:both... UNSUPPORTED OR FAILED. [Sep 18 18:10:01] DEBUG[21544]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 8 on 0x7fa3d8bb7290 [Sep 18 18:10:01] DEBUG[21544]: rtp_engine.c:644 ast_rtp_codecs_payload_formats: Incorporating payload 101 on 0x7fa3d8bb7290 [Sep 18 18:10:01] DEBUG[21544]: res_rtp_asterisk.c:2583 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa3f4005c78' [Sep 18 18:10:01] DEBUG[21544]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 8 from 0x7fa3d8bb7290 to 0x7fa3f4005e40 [Sep 18 18:10:01] DEBUG[21544]: rtp_engine.c:522 ast_rtp_codecs_payloads_copy: Copying payload 101 from 0x7fa3d8bb7290 to 0x7fa3f4005e40 [Sep 18 18:10:01] DEBUG[21544]: res_rtp_asterisk.c:2509 ast_rtp_prop_set: Ignoring duplicate RTCP property on RTP instance '0x7fa3f4005c78' [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9871 process_sdp: We're settling with these formats: 0x8 (alaw) [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:9876 process_sdp: We have an owner, now see if we need to change this call [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:6300 update_call_counter: Updating call counter for outgoing call [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:14850 build_route: build_route: Contact hop: [Sep 18 18:10:01] DEBUG[21544]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '212.79.111.155:5060' into... [Sep 18 18:10:01] DEBUG[21544]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '212.79.111.155' and port '5060'. [Sep 18 18:10:01] DEBUG[21544]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '212.79.111.155:5060' into... [Sep 18 18:10:01] DEBUG[21544]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '212.79.111.155' and port '5060'. [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:3687 __sip_xmit: Trying to put 'ACK sip:212' onto UDP socket destined for 212.79.111.155:5060 [Sep 18 18:10:01] DEBUG[21521]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - outtotest [Sep 18 18:10:01] DEBUG[21521]: chan_sip.c:27193 sip_devicestate: Checking device state for peer outtotest [Sep 18 18:10:01] DEBUG[21521]: devicestate.c:467 do_state_change: Changing state for SIP/outtotest - state 1 (Not in use) [Sep 18 18:10:01] DEBUG[21521]: devicestate.c:442 devstate_event: device 'SIP/outtotest' state '1' [Sep 18 18:10:01] DEBUG[21554]: app_queue.c:1545 handle_statechange: Device 'SIP/outtotest' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. -- SIP/outtotest-00000001 answered SIP/infromclient-00000000 [Sep 18 18:10:01] DEBUG[21557]: rtp_engine.c:1577 ast_rtp_instance_early_bridge: Setting early bridge SDP of 'SIP/infromclient-00000000' with that of 'SIP/outtotest-00000001' [Sep 18 18:10:01] DEBUG[21521]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - infromclient [Sep 18 18:10:01] DEBUG[21521]: chan_sip.c:27193 sip_devicestate: Checking device state for peer infromclient [Sep 18 18:10:01] DEBUG[21521]: devicestate.c:467 do_state_change: Changing state for SIP/infromclient - state 5 (Unavailable) [Sep 18 18:10:01] DEBUG[21521]: devicestate.c:442 devstate_event: device 'SIP/infromclient' state '5' [Sep 18 18:10:01] DEBUG[21554]: app_queue.c:1545 handle_statechange: Device 'SIP/infromclient' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:6892 sip_answer: SIP answering channel: SIP/infromclient-00000000 [Sep 18 18:10:01] DEBUG[21557]: res_rtp_asterisk.c:834 ast_rtp_update_source: Setting the marker bit due to a source update [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:12287 transmit_response_with_sdp: Setting framing from config on incoming call [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:11884 add_sdp: ** Our capability: 0x8 (alaw) Video flag: True Text flag: True [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:11885 add_sdp: ** Our prefcodec: 0x0 (nothing) [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:11994 add_sdp: -- Done with adding codecs to SDP [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:12180 add_sdp: Done building SDP. Settling with this capability: 0x8 (alaw) [Sep 18 18:10:01] DEBUG[21557]: chan_sip.c:3687 __sip_xmit: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.3.25.10:5060 [Sep 18 18:10:01] DEBUG[21557]: features.c:4075 ast_bridge_call: bridge answer set, chan answer set [Sep 18 18:10:01] DEBUG[21557]: features.c:3896 clear_dialed_interfaces: Removing dialed interfaces datastore on SIP/outtotest-00000001 since we're bridging [Sep 18 18:10:01] DEBUG[21557]: res_rtp_asterisk.c:834 ast_rtp_update_source: Setting the marker bit due to a source update [Sep 18 18:10:01] DEBUG[21557]: res_rtp_asterisk.c:834 ast_rtp_update_source: Setting the marker bit due to a source update -- Locally bridging SIP/infromclient-00000000 and SIP/outtotest-00000001 [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:8547 find_call: = Looking for Call ID: 24@10.3.25.10 (Checking From) --From tag 24417923471779367133 --To-tag as731cd300 [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:25870 handle_incoming: **** Received ACK (6) - Command in SIP ACK [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:4371 __sip_ack: Stopping retransmission on '24@10.3.25.10' of Response 2: Match Found [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:01] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:02] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:02] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:03] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:03] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:04] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:04] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:05] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:05] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:06] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:06] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:07] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:07] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:08] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:08] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:09] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:09] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:10] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:10] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:11] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:11] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:12] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:12] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:13] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:13] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:14] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:14] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:15] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:15] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:16] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:16] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:17] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:17] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:18] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:18] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:19] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:19] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:20] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:20] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:21] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:21] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:22] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:22] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:23] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:23] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:24] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:24] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:25] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:25] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:26] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:26] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:27] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:27] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:28] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:28] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:29] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:29] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:30] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:30] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:31] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:31] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:32] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:32] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:33] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:33] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:34] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:34] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:35] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:35] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:36] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:36] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:37] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:37] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:38] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:38] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:39] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:39] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:40] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:40] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:41] DEBUG[21544]: chan_sip.c:26771 proc_session_timer: Session timer expired: 1 - 24@10.3.25.10 [Sep 18 18:10:41] WARNING[21544]: chan_sip.c:26792 proc_session_timer: Session-Timer expired - 24@10.3.25.10 [Sep 18 18:10:41] DEBUG[21544]: channel.c:2735 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/infromclient-00000000' [Sep 18 18:10:41] DEBUG[21544]: chan_sip.c:26812 proc_session_timer: Session timer stopped: 1 - 24@10.3.25.10 [Sep 18 18:10:41] DEBUG[21544]: chan_sip.c:26707 stop_session_timer: Session timer stopped: -1 - 24@10.3.25.10 [Sep 18 18:10:41] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' Method: INVITE [Sep 18 18:10:41] DEBUG[21544]: chan_sip.c:17709 dialog_needdestroy: Bridge still active. Delaying destroy of SIP dialog '24@10.3.25.10' Method: ACK [Sep 18 18:10:41] DEBUG[21557]: rtp_engine.c:893 local_bridge_loop: rtp-engine-local-bridge: Ooh, got a hangup [Sep 18 18:10:41] DEBUG[21557]: channel.c:7630 ast_channel_bridge: Returning from native bridge, channels: SIP/infromclient-00000000, SIP/outtotest-00000001 [Sep 18 18:10:41] DEBUG[21557]: channel.c:2735 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/infromclient-00000000' [Sep 18 18:10:41] DEBUG[21557]: pbx.c:4470 pbx_extension_helper: Launching 'Hangup' -- Executing [h@default:1] Hangup("SIP/infromclient-00000000", "") in new stack [Sep 18 18:10:41] DEBUG[21557]: features.c:4467 ast_bridge_call: Spawn extension (default,h,1) exited non-zero on 'SIP/infromclient-00000000' == Spawn extension (default, h, 1) exited non-zero on 'SIP/infromclient-00000000' [Sep 18 18:10:41] DEBUG[21557]: channel.c:2884 ast_hangup: Hanging up channel 'SIP/outtotest-00000001' [Sep 18 18:10:41] DEBUG[21557]: chan_sip.c:6682 sip_hangup: Hangup call SIP/outtotest-00000001, SIP callid 659653691ee49fc173fd87150ca8f446@10.1.0.19:5060 [Sep 18 18:10:41] DEBUG[21557]: res_rtp_asterisk.c:2583 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x7fa3f4005c78' [Sep 18 18:10:41] DEBUG[21557]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '212.79.111.155:5060' into... [Sep 18 18:10:41] DEBUG[21557]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '212.79.111.155' and port '5060'. [Sep 18 18:10:41] DEBUG[21557]: chan_sip.c:3687 __sip_xmit: Trying to put 'BYE sip:212' onto UDP socket destined for 212.79.111.155:5060 [Sep 18 18:10:41] DEBUG[21557]: app_dial.c:3029 dial_exec_full: Exiting with DIALSTATUS=ANSWER. [Sep 18 18:10:41] DEBUG[21557]: pbx.c:5290 __ast_pbx_run: Spawn extension (default,echo,3) exited non-zero on 'SIP/infromclient-00000000' == Spawn extension (default, echo, 3) exited non-zero on 'SIP/infromclient-00000000' [Sep 18 18:10:41] DEBUG[21557]: channel.c:2735 ast_softhangup_nolock: Soft-Hanging up channel 'SIP/infromclient-00000000' [Sep 18 18:10:41] DEBUG[21557]: channel.c:2884 ast_hangup: Hanging up channel 'SIP/infromclient-00000000' [Sep 18 18:10:41] DEBUG[21557]: chan_sip.c:6682 sip_hangup: Hangup call SIP/infromclient-00000000, SIP callid 24@10.3.25.10 [Sep 18 18:10:41] DEBUG[21557]: res_rtp_asterisk.c:2583 ast_rtp_remote_address_set: Setting RTCP address on RTP instance '0x177ece8' [Sep 18 18:10:41] DEBUG[21557]: netsock2.c:138 ast_sockaddr_split_hostport: Splitting '10.3.25.10:5060' into... [Sep 18 18:10:41] DEBUG[21557]: netsock2.c:192 ast_sockaddr_split_hostport: ...host '10.3.25.10' and port '5060'. [Sep 18 18:10:41] DEBUG[21557]: chan_sip.c:3687 __sip_xmit: Trying to put 'BYE sip:inf' onto UDP socket destined for 10.3.25.10:5060 [Sep 18 18:10:41] DEBUG[21521]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - outtotest [Sep 18 18:10:41] DEBUG[21521]: chan_sip.c:27193 sip_devicestate: Checking device state for peer outtotest [Sep 18 18:10:41] DEBUG[21521]: devicestate.c:467 do_state_change: Changing state for SIP/outtotest - state 1 (Not in use) [Sep 18 18:10:41] DEBUG[21521]: devicestate.c:442 devstate_event: device 'SIP/outtotest' state '1' [Sep 18 18:10:41] DEBUG[21554]: app_queue.c:1545 handle_statechange: Device 'SIP/outtotest' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Sep 18 18:10:41] DEBUG[21521]: devicestate.c:344 _ast_device_state: No provider found, checking channel drivers for SIP - infromclient [Sep 18 18:10:41] DEBUG[21521]: chan_sip.c:27193 sip_devicestate: Checking device state for peer infromclient [Sep 18 18:10:41] DEBUG[21521]: devicestate.c:467 do_state_change: Changing state for SIP/infromclient - state 5 (Unavailable) [Sep 18 18:10:41] DEBUG[21521]: devicestate.c:442 devstate_event: device 'SIP/infromclient' state '5' [Sep 18 18:10:41] DEBUG[21554]: app_queue.c:1545 handle_statechange: Device 'SIP/infromclient' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Sep 18 18:10:41] DEBUG[21544]: chan_sip.c:8547 find_call: = Looking for Call ID: 24@10.3.25.10 (Checking To) --From tag as731cd300 --To-tag 24417923471779367133 [Sep 18 18:10:41] DEBUG[21544]: chan_sip.c:4371 __sip_ack: Stopping retransmission on '24@10.3.25.10' of Request 102: Match Found [Sep 18 18:10:41] DEBUG[21544]: chan_sip.c:6448 sip_destroy: Destroying SIP dialog 24@10.3.25.10 [Sep 18 18:10:41] DEBUG[21544]: rtp_engine.c:298 instance_destructor: Destroyed RTP instance '0x177ece8' [Sep 18 18:10:41] DEBUG[21544]: chan_sip.c:8547 find_call: = Looking for Call ID: 659653691ee49fc173fd87150ca8f446@10.1.0.19:5060 (Checking To) --From tag as1672d8e0 --To-tag 08B58658-5239D05900013367-EC64A700 [Sep 18 18:10:41] DEBUG[21544]: chan_sip.c:4371 __sip_ack: Stopping retransmission on '659653691ee49fc173fd87150ca8f446@10.1.0.19:5060' of Request 103: Match Found [Sep 18 18:10:41] DEBUG[21544]: chan_sip.c:6448 sip_destroy: Destroying SIP dialog 659653691ee49fc173fd87150ca8f446@10.1.0.19:5060 [Sep 18 18:10:41] DEBUG[21544]: rtp_engine.c:298 instance_destructor: Destroyed RTP instance '0x7fa3f4005c78'