[Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg INVITE/cseq=20 (rdata0x7f65280016b8) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000028 to use for Request msg INVITE/cseq=20 (rdata0x7f65280016b8) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_endpoint_identifier_ip.c:258 ip_identify_match_check: Source address 10.8.0.2:5060 does not match identify 'trunk-linhome-identify' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username '6000' domain '192.168.0.17' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username '6000' domain '192.168.0.17' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_authenticator_digest.c:471 digest_check_auth: Using default realm 'asterisk' on incoming auth 'auth6000'. [Jun 7 13:48:23] DEBUG[570]: res_pjsip_authenticator_digest.c:358 verify: Realm: asterisk Username: 6000 Result: NOAUTH [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg ACK/cseq=20 (rdata0x7f65280016b8) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000028 to use for Request msg ACK/cseq=20 (rdata0x7f65280016b8) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_endpoint_identifier_ip.c:258 ip_identify_match_check: Source address 10.8.0.2:5060 does not match identify 'trunk-linhome-identify' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username '6000' domain '192.168.0.17' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username '6000' domain '192.168.0.17' [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg INVITE/cseq=21 (rdata0x7f65280016b8) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000028 to use for Request msg INVITE/cseq=21 (rdata0x7f65280016b8) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_endpoint_identifier_ip.c:258 ip_identify_match_check: Source address 10.8.0.2:5060 does not match identify 'trunk-linhome-identify' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username '6000' domain '192.168.0.17' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username '6000' domain '192.168.0.17' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_authenticator_digest.c:471 digest_check_auth: Using default realm 'asterisk' on incoming auth 'auth6000'. [Jun 7 13:48:23] DEBUG[570]: res_pjsip_authenticator_digest.c:261 check_nonce: Calculated nonce 1654602503/91874651996c935e49202c075a627b5c. Actual nonce is 1654602503/91874651996c935e49202c075a627b5c [Jun 7 13:48:23] DEBUG[570]: res_pjsip_authenticator_digest.c:358 verify: Realm: asterisk Username: 6000 Result: SUCCESS [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4235 session_on_rx_request: (null session) Request: INVITE [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4062 handle_new_invite_request: Request: [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000028 to use for Request msg INVITE/cseq=21 (rdata0x7f652806ba38) [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2954 chan_pjsip_session_begin: 6000 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2958 chan_pjsip_session_begin: Direct media no glare mitigation [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:3916 new_invite: 6000 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:3996 new_invite: 6000: Call (UDP:10.8.0.2:5060) to extension '1' sending 100 Trying [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4514 handle_outgoing_response: 6000: Method is INVITE, Response is 100 Trying [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4533 handle_outgoing_response: 6000 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4630 session_inv_on_state_changed: 6000 Event: TSX_STATE Inv State: INCOMING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4656 session_inv_on_state_changed: 6000: Source of transaction state change is TX_MSG [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4704 session_inv_on_state_changed: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: 6000 TSX State: Proceeding Inv State: INCOMING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: 6000 TSX State: Proceeding Inv State: INCOMING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: (null topology) Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:769 handle_incoming_sdp: 6000: Media count: 1 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:495 ast_sip_session_media_state_add: 6000 Adding position 0 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:541 ast_sip_session_media_state_add: Creating new media session [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:584 ast_sip_session_media_state_add: Setting media session as default for audio [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:589 ast_sip_session_media_state_add: Done [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:1504 negotiate_incoming_sdp_stream: 6000 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:526 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7f652c092570' [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:3871 rtp_allocate_transport: (0x7f652c092570) RTP allocated port 15244 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:3901 rtp_allocate_transport: (0x7f652c092570) ICE creating session [::]:15244 (15244) [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:3780 ice_create: (0x7f652c092570) ICE create [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:3557 rtp_add_candidates_to_ice: (0x7f652c092570) ICE add system candidates [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: 192.168.0.17:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: 172.17.0.1:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: 172.30.32.1:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::42:a6ff:fea0:e787]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::42:81ff:fe8d:8edb]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::286b:5eff:feb6:d8b0]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::6cfa:a6ff:feca:18c1]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::20eb:69ff:fe78:22a0]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::dc9d:7cff:fe81:b3f5]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::486:a0ff:fe22:a67b]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::2008:72ff:fec5:8284]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::7c8d:61ff:feca:8146]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::9c3b:96ff:fe02:eaba]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::7837:92ff:feb4:b1b]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::a84a:a8ff:fe17:4f9a]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::8000:8eff:fe81:3bd1]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: [fe80::b0d0:bdff:fe54:bdaa]:15244, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:3663 rtp_add_candidates_to_ice: (0x7f652c092570) ICE request STUN TCP RTP candidate [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c092570) ICE add candidate: 84.193.34.18:15244, 1694498815 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:543 ast_rtp_instance_new: RTP instance '0x7f652c092570' is setup and ready to go [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:918 ast_rtp_ice_stop: (0x7f652c092570) ICE stopped [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:8440 ast_rtp_prop_set: (0x7f652c092570) RTCP setup on RTP instance [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:456 set_incoming_call_offer_cap: 6000 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:328 get_codecs: 6000 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1310 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 0 based on m type on 0x7f64f0867500 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1310 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 8 based on m type on 0x7f64f0867500 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:415 get_codecs: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session/pjsip_session_caps.c:161 ast_sip_session_create_joint_call_cap: '6000' Caps for incoming audio call with pref 'local' - remote: (ulaw|alaw) local: (ulaw|alaw|h264|vp8) joint: (ulaw|alaw) [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1274 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 0 (0x55f95560f2e8) from 0x7f64f0867500 to 0x7f64f0867500 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1274 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 8 (0x55f95560f4c8) from 0x7f64f0867500 to 0x7f64f0867500 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1113 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 0 (0x55f95560f2e8) from 0x7f64f0867500 to 0x7f652c092748 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1113 rtp_codecs_payloads_copy_rx: Copying rx payload mapping 8 (0x55f95560f4c8) from 0x7f64f0867500 to 0x7f652c092748 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1196 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 0 (0x55f95560f2e8) from 0x7f64f0867500 to 0x7f652c092748 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1196 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 8 (0x55f95560f4c8) from 0x7f64f0867500 to 0x7f652c092748 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:491 set_incoming_call_offer_cap: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:1594 negotiate_incoming_sdp_stream: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:960 handle_incoming_sdp: 6000: Handled? yes [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5100 create_local_sdp: 6000 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5137 create_local_sdp: 6000: Processing streams [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:495 ast_sip_session_media_state_add: 6000 Adding position 0 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:503 ast_sip_session_media_state_add: Using existing media_session [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4976 add_sdp_streams: 6000 Stream: 0:audio-0:audio:sendrecv (ulaw|alaw) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:1749 create_outgoing_sdp_stream: 6000 Type: audio 0:audio-0:audio:sendrecv (ulaw|alaw) [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:8339 ast_rtp_prop_set: (0x7f652c092570) RTCP ignoring duplicate property [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:2034 create_outgoing_sdp_stream: RC: 1 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4985 add_sdp_streams: Had handler [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5194 create_local_sdp: 6000: Adding bundle groups (if available) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5200 create_local_sdp: 6000: Copying connection details [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5244 create_local_sdp: 6000 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4413 handle_incoming_request: 6000: Method is INVITE [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3013 chan_pjsip_incoming_request: 6000 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:555 chan_pjsip_new: 6000 [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:680 ast_channel_nativeformats_set: : Formats: (none) [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:692 ast_channel_nativeformats_set: Channel is being initialized or destroyed [Jun 7 13:48:23] DEBUG[570]: stasis.c:580 stasis_topic_create_with_detail: Creating topic. name: channel:1654602503.3, detail: [Jun 7 13:48:23] DEBUG[570]: stasis.c:614 stasis_topic_create_with_detail: Topic 'channel:1654602503.3': 0x7f652c025b70 created [Jun 7 13:48:23] DEBUG[540]: threadpool.c:536 grow: Increasing threadpool stasis/pool's size by 1 [Jun 7 13:48:23] DEBUG[570]: channel.c:949 __ast_channel_alloc_ap: Channel 0x7f652c05b570 'PJSIP/6000-00000002' allocated [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:530 compatible_formats_exist: Topology: <0:audio-0:audio:sendrecv (ulaw|alaw)> Formats: (ulaw|alaw|h264|vp8) [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:543 compatible_formats_exist: Compatible? yes [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:680 ast_channel_nativeformats_set: PJSIP/6000-00000002: MultistreamFormats: (ulaw|alaw) [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:702 ast_channel_nativeformats_set: Set native formats but not topology [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:1595 ast_channel_set_stream_topology: PJSIP/6000-00000002: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:1616 ast_channel_set_stream_topology: Used provided topology [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:675 chan_pjsip_new: [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3063 chan_pjsip_incoming_request: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3119 pbx_start_incoming_request: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3145 pbx_start_incoming_request: Started PBX on new PJSIP channel PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3147 pbx_start_incoming_request: RC: 0 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4423 handle_incoming_request: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4045 new_invite: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4136 handle_new_invite_request: Request: Session: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4254 session_on_rx_request: (null session) Handled request INVITE ? yes [Jun 7 13:48:23] DEBUG[658][C-00000002]: pbx.c:2936 pbx_extension_helper: Launching 'NoOp' [Jun 7 13:48:23]  -- Executing [1@default:1] NoOp("PJSIP/6000-00000002", "") in new stack [Jun 7 13:48:23] DEBUG[658][C-00000002]: pbx.c:2936 pbx_extension_helper: Launching 'Progress' [Jun 7 13:48:23]  -- Executing [1@default:2] Progress("PJSIP/6000-00000002", "") in new stack [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Progress [Jun 7 13:48:23] DEBUG[552]: devicestate.c:466 do_state_change: Changing state for PJSIP/6000 - state 2 (In use) [Jun 7 13:48:23] DEBUG[639]: app_queue.c:2683 device_state_cb: Device 'PJSIP/6000' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5349 session_inv_on_media_update: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:1068 handle_negotiated_sdp: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:974 handle_negotiated_sdp_session_media: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:2092 apply_negotiated_sdp_stream: PJSIP/6000-00000002 Stream: 0:audio-0:audio:sendrecv (ulaw|alaw) [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:8339 ast_rtp_prop_set: (0x7f652c092570) RTCP ignoring duplicate property [Jun 7 13:48:23] DEBUG[570]: acl.c:1045 ast_ouraddrfor: For destination '10.8.0.2', our source address is '192.168.0.17'. [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:8542 ast_rtp_remote_address_set: (0x7f652c092570) RTCP setting address on RTP instance [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:508 set_caps: PJSIP/6000-00000002 ANSWER [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:328 get_codecs: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1310 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 0 based on m type on 0x7f64f0867280 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1310 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 8 based on m type on 0x7f64f0867280 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:415 get_codecs: [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1196 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 0 (0x55f95560f2e8) from 0x7f64f0867280 to 0x7f652c092748 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:1196 rtp_codecs_payloads_copy_tx: Copying tx payload mapping 8 (0x55f95560f4c8) from 0x7f64f0867280 to 0x7f652c092748 [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:680 ast_channel_nativeformats_set: PJSIP/6000-00000002: MultistreamFormats: (ulaw) [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:702 ast_channel_nativeformats_set: Set native formats but not topology [Jun 7 13:48:23] DEBUG[570]: channel.c:5821 set_format: Channel PJSIP/6000-00000002 setting read format path: ulaw -> ulaw [Jun 7 13:48:23] DEBUG[570]: channel.c:5821 set_format: Channel PJSIP/6000-00000002 setting write format path: ulaw -> ulaw [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:618 set_caps: [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:9119 ast_rtp_activate: (0x7f652c092570) DTLS - ast_rtp_activate rtp=0x7f652c02f4e0 - setup and perform DTLS' [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:2548 dtls_perform_handshake: (0x7f652c02f4e0) DTLS perform handshake - ssl = (nil), setup = 0 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:2548 dtls_perform_handshake: (0x7f652c02f4e0) DTLS perform handshake - ssl = (nil), setup = 0 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:2242 apply_negotiated_sdp_stream: Handled [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:1013 handle_negotiated_sdp_session_media: PJSIP/6000-00000002: Applied negotiated SDP media stream 'audio' using audio SDP handler [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:1595 ast_channel_set_stream_topology: PJSIP/6000-00000002: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:1616 ast_channel_set_stream_topology: Used provided topology [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:1223 handle_negotiated_sdp: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5413 session_inv_on_media_update: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4514 handle_outgoing_response: PJSIP/6000-00000002: Method is INVITE, Response is 183 Session Progress [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4533 handle_outgoing_response: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4630 session_inv_on_state_changed: PJSIP/6000-00000002 Event: TSX_STATE Inv State: EARLY [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4656 session_inv_on_state_changed: PJSIP/6000-00000002: Source of transaction state change is TX_MSG [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4704 session_inv_on_state_changed: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/6000-00000002 TSX State: Proceeding Inv State: EARLY [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/6000-00000002 TSX State: Proceeding Inv State: EARLY [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[658][C-00000002]: pbx.c:2936 pbx_extension_helper: Launching 'Set' [Jun 7 13:48:23]  -- Executing [1@default:3] Set("PJSIP/6000-00000002", "CALLERID(num)=yyy") in new stack [Jun 7 13:48:23] DEBUG[658][C-00000002]: pbx.c:2936 pbx_extension_helper: Launching 'Set' [Jun 7 13:48:23]  -- Executing [1@default:4] Set("PJSIP/6000-00000002", "CALLERID(name)=") in new stack [Jun 7 13:48:23] DEBUG[658][C-00000002]: pbx.c:2936 pbx_extension_helper: Launching 'Set' [Jun 7 13:48:23]  -- Executing [1@default:5] Set("PJSIP/6000-00000002", "__DYNAMIC_FEATURES=door") in new stack [Jun 7 13:48:23] DEBUG[658][C-00000002]: pbx.c:2936 pbx_extension_helper: Launching 'Dial' [Jun 7 13:48:23]  -- Executing [1@default:6] Dial("PJSIP/6000-00000002", "PJSIP/xxx@trunk-linhome") in new stack [Jun 7 13:48:23] DEBUG[658][C-00000002]: app_dial.c:2354 dial_exec_full: PJSIP/6000-00000002: Data: PJSIP/xxx@trunk-linhome [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:2672 chan_pjsip_request_with_stream_topology: xxx@trunk-linhome Topology: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2571 request: xxx@trunk-linhome [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:3330 ast_sip_session_create_outgoing: trunk-linhome xxx Topology: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2954 chan_pjsip_session_begin: trunk-linhome [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2958 chan_pjsip_session_begin: Direct media no glare mitigation [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session/pjsip_session_caps.c:146 ast_sip_session_create_joint_call_stream: 'trunk-linhome' Caps for outgoing audio call with pref 'remote_merge' - remote: (ulaw|alaw) local: (ulaw|alaw|h264) joint: (ulaw|alaw) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:3446 ast_sip_session_create_outgoing: [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2664 request: [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:555 chan_pjsip_new: trunk-linhome [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel_internal_api.c:680 ast_channel_nativeformats_set: : Formats: (none) [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel_internal_api.c:692 ast_channel_nativeformats_set: Channel is being initialized or destroyed [Jun 7 13:48:23] DEBUG[658][C-00000002]: stasis.c:580 stasis_topic_create_with_detail: Creating topic. name: channel:1654602503.4, detail: [Jun 7 13:48:23] DEBUG[658][C-00000002]: stasis.c:614 stasis_topic_create_with_detail: Topic 'channel:1654602503.4': 0x7f650c00b9a0 created [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:949 __ast_channel_alloc_ap: Channel 0x7f650c00d310 'PJSIP/trunk-linhome-00000003' allocated [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:530 compatible_formats_exist: Topology: <0:audio-0:audio:sendrecv (ulaw|alaw)> Formats: (ulaw|alaw|h264) [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:543 compatible_formats_exist: Compatible? yes [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel_internal_api.c:680 ast_channel_nativeformats_set: PJSIP/trunk-linhome-00000003: MultistreamFormats: (ulaw|alaw) [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel_internal_api.c:702 ast_channel_nativeformats_set: Set native formats but not topology [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel_internal_api.c:1595 ast_channel_set_stream_topology: PJSIP/trunk-linhome-00000003: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel_internal_api.c:1616 ast_channel_set_stream_topology: Used provided topology [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:675 chan_pjsip_new: [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:2692 chan_pjsip_request_with_stream_topology: Channel: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:6881 ast_channel_inherit_variables: Inheriting variable __DYNAMIC_FEATURES from PJSIP/6000-00000002 to PJSIP/trunk-linhome-00000003. [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:2389 chan_pjsip_call: PJSIP/trunk-linhome-00000003 Topology: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2365 call: PJSIP/trunk-linhome-00000003 Topology: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:2851 ast_sip_session_create_invite: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5100 create_local_sdp: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5137 create_local_sdp: PJSIP/trunk-linhome-00000003: Processing streams [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:495 ast_sip_session_media_state_add: PJSIP/trunk-linhome-00000003 Adding position 0 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:541 ast_sip_session_media_state_add: Creating new media session [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:584 ast_sip_session_media_state_add: Setting media session as default for audio [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:589 ast_sip_session_media_state_add: Done [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4976 add_sdp_streams: PJSIP/trunk-linhome-00000003 Stream: 0:audio-0:audio:sendrecv (ulaw|alaw) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:1749 create_outgoing_sdp_stream: PJSIP/trunk-linhome-00000003 Type: audio 0:audio-0:audio:sendrecv (ulaw|alaw) [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:526 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7f652c04ca30' [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:3871 rtp_allocate_transport: (0x7f652c04ca30) RTP allocated port 19702 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:3901 rtp_allocate_transport: (0x7f652c04ca30) ICE creating session [::]:19702 (19702) [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:3780 ice_create: (0x7f652c04ca30) ICE create [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:3557 rtp_add_candidates_to_ice: (0x7f652c04ca30) ICE add system candidates [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: 192.168.0.17:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: 172.17.0.1:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: 172.30.32.1:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::42:a6ff:fea0:e787]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::42:81ff:fe8d:8edb]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::286b:5eff:feb6:d8b0]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::6cfa:a6ff:feca:18c1]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::20eb:69ff:fe78:22a0]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::dc9d:7cff:fe81:b3f5]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::486:a0ff:fe22:a67b]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::2008:72ff:fec5:8284]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::7c8d:61ff:feca:8146]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::9c3b:96ff:fe02:eaba]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::7837:92ff:feb4:b1b]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::a84a:a8ff:fe17:4f9a]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::8000:8eff:fe81:3bd1]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: [fe80::b0d0:bdff:fe54:bdaa]:19702, 2130706431 [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:3663 rtp_add_candidates_to_ice: (0x7f652c04ca30) ICE request STUN TCP RTP candidate [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:2399 chan_pjsip_call: 'call' task pushed [Jun 7 13:48:23]  -- Called PJSIP/xxx@trunk-linhome [Jun 7 13:48:23] DEBUG[658][C-00000002]: app_dial.c:1247 wait_for_answer: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:5821 set_format: Channel PJSIP/trunk-linhome-00000003 setting read format path: ulaw -> ulaw [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:5821 set_format: Channel PJSIP/6000-00000002 setting write format path: ulaw -> ulaw [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:5821 set_format: Channel PJSIP/6000-00000002 setting read format path: ulaw -> ulaw [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:5821 set_format: Channel PJSIP/trunk-linhome-00000003 setting write format path: ulaw -> ulaw [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7f652c04ca30) ICE add candidate: 84.193.34.18:19702, 1694498815 [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:543 ast_rtp_instance_new: RTP instance '0x7f652c04ca30' is setup and ready to go [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:918 ast_rtp_ice_stop: (0x7f652c04ca30) ICE stopped [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:8440 ast_rtp_prop_set: (0x7f652c04ca30) RTCP setup on RTP instance [Jun 7 13:48:23] DEBUG[570]: res_pjsip_sdp_rtp.c:2034 create_outgoing_sdp_stream: RC: 1 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5006 add_sdp_streams: Handled [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5194 create_local_sdp: PJSIP/trunk-linhome-00000003: Adding bundle groups (if available) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5200 create_local_sdp: PJSIP/trunk-linhome-00000003: Copying connection details [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5244 create_local_sdp: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:2876 ast_sip_session_create_invite: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4496 handle_outgoing_request: PJSIP/trunk-linhome-00000003: Method is INVITE [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4506 handle_outgoing_request: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:475 sip_resolve: Performing SIP DNS resolution of target 'sip.linhome.org' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:502 sip_resolve: Transport type for target 'sip.linhome.org' is 'Unspecified' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:545 sip_resolve: [0x7f652c054058] Created resolution tracking for target 'sip.linhome.org' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c054058] Added target 'sip.linhome.org' with record type '35', transport 'Unspecified', and port '0' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c054058] Added target '_sips._tcp.sip.linhome.org' with record type '33', transport 'TLS transport', and port '5061' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c054058] Added target '_sip._tcp.sip.linhome.org' with record type '33', transport 'TCP transport', and port '5060' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c054058] Added target '_sip._udp.sip.linhome.org' with record type '33', transport 'UDP transport', and port '5060' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c054058] Added target 'sip.linhome.org' with record type '1', transport 'UDP transport', and port '5060' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:616 sip_resolve: [0x7f652c054058] Starting initial resolution using parallel queries for target 'sip.linhome.org' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4630 session_inv_on_state_changed: PJSIP/trunk-linhome-00000003 Event: TSX_STATE Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4656 session_inv_on_state_changed: PJSIP/trunk-linhome-00000003: Source of transaction state change is TX_MSG [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4704 session_inv_on_state_changed: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Calling Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Calling Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2382 call: RC: 0 [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Connected line update [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[554]: dns.c:555 ast_search_dns_ex: DNS search failed for sip.linhome.org [Jun 7 13:48:23] DEBUG[554]: dns_system_resolver.c:154 dns_system_resolver_process_query: DNS search failed for query: 'sip.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:273 sip_resolve_callback: [0x7f652c054058] All parallel queries completed [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c054058] SRV record received on target '_sips._tcp.sip.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c054058] Added target 'sip6.linhome.org' with record type '1', transport 'TLS transport', and port '5061' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c054058] SRV record received on target '_sips._tcp.sip.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c054058] Added target 'sip1.linhome.org' with record type '1', transport 'TLS transport', and port '5061' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c054058] SRV record received on target '_sip._tcp.sip.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c054058] Added target 'sip6.linhome.org' with record type '1', transport 'TCP transport', and port '5060' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c054058] SRV record received on target '_sip._tcp.sip.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c054058] Added target 'sip1.linhome.org' with record type '1', transport 'TCP transport', and port '5060' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c054058] SRV record received on target '_sip._udp.sip.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c054058] Added target 'sip6.linhome.org' with record type '1', transport 'UDP transport', and port '5060' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c054058] SRV record received on target '_sip._udp.sip.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c054058] Added target 'sip1.linhome.org' with record type '1', transport 'UDP transport', and port '5060' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:307 sip_resolve_callback: [0x7f652c054058] A record being skipped on target 'sip.linhome.org' because NAPTR or SRV record exists [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:411 sip_resolve_callback: [0x7f652c054058] New queries added, performing parallel resolution again [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:273 sip_resolve_callback: [0x7f652c054058] All parallel queries completed [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c054058] A record received on target 'sip6.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c054058] A record received on target 'sip1.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c054058] A record received on target 'sip6.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c054058] A record received on target 'sip1.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c054058] A record received on target 'sip6.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c054058] A record received on target 'sip1.linhome.org' [Jun 7 13:48:23] DEBUG[554]: res_pjsip/pjsip_resolver.c:417 sip_resolve_callback: [0x7f652c054058] Resolution completed - 6 viable targets [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c054058] Address '0' is 54.37.202.229:5061 with transport 'TLS transport' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c054058] Address '1' is 91.121.209.194:5061 with transport 'TLS transport' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c054058] Address '2' is 54.37.202.229:5060 with transport 'TCP transport' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c054058] Address '3' is 91.121.209.194:5060 with transport 'TCP transport' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c054058] Address '4' is 54.37.202.229:5060 with transport 'UDP transport' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c054058] Address '5' is 91.121.209.194:5060 with transport 'UDP transport' [Jun 7 13:48:23] DEBUG[570]: res_pjsip/pjsip_resolver.c:205 sip_resolve_invoke_user_callback: [0x7f652c054058] Invoking user callback with '6' addresses [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c033b98 for Response msg 407/INVITE/cseq=49 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/outsess/trunk-linhome-00000069 associated with dialog dlg0x7f652c033b98 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:3269 outbound_invite_auth: PJSIP/trunk-linhome-00000003: Initial INVITE is being challenged. [Jun 7 13:48:23] DEBUG[570]: res_pjsip_outbound_authenticator_digest.c:227 set_outbound_authentication_credentials: Searching auths to find matching ones for header with realm 'sip.linhome.org' and algorithm 'MD5' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_outbound_authenticator_digest.c:271 set_outbound_authentication_credentials: Found wildcard auth 'trunk-linhome-auth' for realm 'sip.linhome.org' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_outbound_authenticator_digest.c:301 set_outbound_authentication_credentials: Using wildcard auth 'trunk-linhome-auth' for realm 'sip.linhome.org' [Jun 7 13:48:23] DEBUG[570]: res_pjsip_outbound_authenticator_digest.c:387 set_outbound_authentication_credentials: Set 1 credentials in auth session [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4496 handle_outgoing_request: PJSIP/trunk-linhome-00000003: Method is INVITE [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4506 handle_outgoing_request: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Calling Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Calling Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Completed Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4465 handle_incoming_response: PJSIP/trunk-linhome-00000003: Response is 407 Proxy Authentication Required [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3190 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Status: 407 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3235 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Not queueing anything [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3239 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3162 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003: Status: 407 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3183 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4477 handle_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Completed Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Private Cause Code [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Terminated Inv State: CALLING [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Terminated Inv State: CALLING [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c033b98 for Response msg 100/INVITE/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/outsess/trunk-linhome-00000069 associated with dialog dlg0x7f652c033b98 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4203 session_on_rx_response: PJSIP/trunk-linhome-00000003 Method: INVITE Status: 100 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4206 session_on_rx_response: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4465 handle_incoming_response: PJSIP/trunk-linhome-00000003: Response is 100 Trying [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3190 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Status: 100 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3235 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Not queueing anything [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3239 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3162 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003: Status: 100 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3183 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4477 handle_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Private Cause Code [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c033b98 for Response msg 180/INVITE/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/outsess/trunk-linhome-00000069 associated with dialog dlg0x7f652c033b98 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4203 session_on_rx_response: PJSIP/trunk-linhome-00000003 Method: INVITE Status: 180 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4206 session_on_rx_response: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4465 handle_incoming_response: PJSIP/trunk-linhome-00000003: Response is 180 Ringing [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3190 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3203 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Queueing RINGING [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3239 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3162 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3183 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4477 handle_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23]  -- PJSIP/trunk-linhome-00000003 is ringing [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Ringing [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4514 handle_outgoing_response: PJSIP/6000-00000002: Method is INVITE, Response is 183 Session Progress [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:4670 indicate_data_internal: Driver for channel 'PJSIP/6000-00000002' does not support indication 3, emulating it [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:5821 set_format: Channel PJSIP/6000-00000002 setting write format path: slin -> ulaw [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:3207 ast_settimeout_full: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:5042 ast_prod: Prodding channel 'PJSIP/6000-00000002' [Jun 7 13:48:23] DEBUG[658][C-00000002]: res_rtp_asterisk.c:5344 ast_rtp_write: (0x7f652c092570) RTP received frame with no data for instance, so dropping frame [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4533 handle_outgoing_response: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4630 session_inv_on_state_changed: PJSIP/6000-00000002 Event: TSX_STATE Inv State: EARLY [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4656 session_inv_on_state_changed: PJSIP/6000-00000002: Source of transaction state change is TX_MSG [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4704 session_inv_on_state_changed: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/6000-00000002 TSX State: Proceeding Inv State: EARLY [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/6000-00000002 TSX State: Proceeding Inv State: EARLY [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[540]: threadpool.c:536 grow: Increasing threadpool stasis/pool's size by 1 [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Private Cause Code [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c033b98 for Response msg 180/INVITE/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/outsess/trunk-linhome-00000069 associated with dialog dlg0x7f652c033b98 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4203 session_on_rx_response: PJSIP/trunk-linhome-00000003 Method: INVITE Status: 180 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4206 session_on_rx_response: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4465 handle_incoming_response: PJSIP/trunk-linhome-00000003: Response is 180 Ringing [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3190 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3203 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Queueing RINGING [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3239 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3162 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3183 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4477 handle_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23]  -- PJSIP/trunk-linhome-00000003 is ringing [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Private Cause Code [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c033b98 for Response msg 180/INVITE/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/outsess/trunk-linhome-00000069 associated with dialog dlg0x7f652c033b98 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4203 session_on_rx_response: PJSIP/trunk-linhome-00000003 Method: INVITE Status: 180 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4206 session_on_rx_response: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4465 handle_incoming_response: PJSIP/trunk-linhome-00000003: Response is 180 Ringing [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3190 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3203 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Queueing RINGING [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3239 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3162 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3183 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4477 handle_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23]  -- PJSIP/trunk-linhome-00000003 is ringing [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Private Cause Code [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c033b98 for Response msg 180/INVITE/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/outsess/trunk-linhome-00000069 associated with dialog dlg0x7f652c033b98 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4203 session_on_rx_response: PJSIP/trunk-linhome-00000003 Method: INVITE Status: 180 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4206 session_on_rx_response: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4465 handle_incoming_response: PJSIP/trunk-linhome-00000003: Response is 180 Ringing [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3190 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3203 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Queueing RINGING [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3239 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3162 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3183 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4477 handle_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23]  -- PJSIP/trunk-linhome-00000003 is ringing [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Private Cause Code [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c033b98 for Response msg 180/INVITE/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/outsess/trunk-linhome-00000069 associated with dialog dlg0x7f652c033b98 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4203 session_on_rx_response: PJSIP/trunk-linhome-00000003 Method: INVITE Status: 180 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4206 session_on_rx_response: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4465 handle_incoming_response: PJSIP/trunk-linhome-00000003: Response is 180 Ringing [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3190 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3203 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Queueing RINGING [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3239 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3162 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3183 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4477 handle_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[552]: devicestate.c:466 do_state_change: Changing state for PJSIP/trunk-linhome - state 6 (Ringing) [Jun 7 13:48:23] DEBUG[552]: devicestate.c:466 do_state_change: Changing state for PJSIP/6000 - state 2 (In use) [Jun 7 13:48:23] DEBUG[639]: app_queue.c:2683 device_state_cb: Device 'PJSIP/trunk-linhome' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Jun 7 13:48:23]  -- PJSIP/trunk-linhome-00000003 is ringing [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Private Cause Code [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c033b98 for Response msg 180/INVITE/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/outsess/trunk-linhome-00000069 associated with dialog dlg0x7f652c033b98 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4203 session_on_rx_response: PJSIP/trunk-linhome-00000003 Method: INVITE Status: 180 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4206 session_on_rx_response: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4465 handle_incoming_response: PJSIP/trunk-linhome-00000003: Response is 180 Ringing [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3190 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3203 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Queueing RINGING [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3239 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3162 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003: Status: 180 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3183 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4477 handle_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: CALLING [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23]  -- PJSIP/trunk-linhome-00000003 is ringing [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Private Cause Code [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[658][C-00000002]: res_rtp_asterisk.c:5376 ast_rtp_write: (0x7f652c092570) RTP ooh, format changed from none to ulaw [Jun 7 13:48:23] DEBUG[658][C-00000002]: res_rtp_asterisk.c:5118 rtp_raw_write: (0x7f652c092570) RTCP starting transmission [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c033b98 for Response msg 183/INVITE/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/outsess/trunk-linhome-00000069 associated with dialog dlg0x7f652c033b98 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4203 session_on_rx_response: PJSIP/trunk-linhome-00000003 Method: INVITE Status: 183 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4206 session_on_rx_response: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4630 session_inv_on_state_changed: PJSIP/trunk-linhome-00000003 Event: TSX_STATE Inv State: EARLY [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4656 session_inv_on_state_changed: PJSIP/trunk-linhome-00000003: Source of transaction state change is RX_MSG [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4598 handle_incoming_before_media: PJSIP/trunk-linhome-00000003: Received response [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4465 handle_incoming_response: PJSIP/trunk-linhome-00000003: Response is 183 Session progress [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3162 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003: Status: 183 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3183 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4477 handle_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4704 session_inv_on_state_changed: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5349 session_inv_on_media_update: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Private Cause Code [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:5406 session_inv_on_media_update: PJSIP/trunk-linhome-00000003: Couldn't get active or local or remote negotiator. Hanging up [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: EARLY [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4465 handle_incoming_response: PJSIP/trunk-linhome-00000003: Response is 183 Session progress [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3190 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Status: 183 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3224 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003: Queueing PROGRESS [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3225 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003 Method: INVITE Status: 183 Queueing PROGRESS without SDP [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:2549 ast_hangup: Channel 0x7f650c00d310 'PJSIP/trunk-linhome-00000003' hanging up. Refs: 2 [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:2522 chan_pjsip_hangup: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:2540 chan_pjsip_hangup: Cause: 488 [Jun 7 13:48:23]  == Everyone is busy/congested at this time (1:0/0/1) [Jun 7 13:48:23] DEBUG[658][C-00000002]: app_dial.c:1306 wait_for_answer: PJSIP/6000-00000002: No outging channels available [Jun 7 13:48:23] DEBUG[658][C-00000002]: app_dial.c:3429 dial_exec_full: Exiting with DIALSTATUS=CHANUNAVAIL. [Jun 7 13:48:23] DEBUG[658][C-00000002]: app_dial.c:3460 dial_exec_full: PJSIP/6000-00000002: Done [Jun 7 13:48:23]  -- Auto fallthrough, channel 'PJSIP/6000-00000002' status is 'CHANUNAVAIL' [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1632 chan_pjsip_indicate: PJSIP/6000-00000002: Indicated Congestion [Jun 7 13:48:23] DEBUG[560]: cdr.c:1473 cdr_object_finalize: Finalized CDR for PJSIP/6000-00000002 - start 1654602503.284395 answer 0.000000 end 1654602503.523165 dur 0.238 bill 1654602503.523 dispo NO ANSWER [Jun 7 13:48:23] DEBUG[567]: threadpool.c:536 grow: Increasing threadpool pjsip/pool's size by 5 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3239 chan_pjsip_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3162 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003: Status: 183 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3183 chan_pjsip_incoming_response_update_cause: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4477 handle_incoming_response: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Proceeding Inv State: EARLY [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: <0:audio-0:audio:sendrecv (ulaw|alaw)> Active: (null topology) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2489 hangup: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:3456 ast_sip_session_terminate: PJSIP/trunk-linhome-00000003 Response 488 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4496 handle_outgoing_request: PJSIP/trunk-linhome-00000003: Method is CANCEL [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4506 handle_outgoing_request: PJSIP/trunk-linhome-00000003 [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:1843 chan_pjsip_indicate: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[552]: devicestate.c:466 do_state_change: Changing state for PJSIP/6000 - state 3 (Busy) [Jun 7 13:48:23] DEBUG[639]: app_queue.c:2683 device_state_cb: Device 'PJSIP/6000' changed to state '3' (Busy) but we don't care because they're not a member of any queue. [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/trunk-linhome-00000003 TSX State: Calling Inv State: EARLY [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:4514 handle_outgoing_response: PJSIP/6000-00000002: Method is INVITE, Response is 503 Service Unavailable [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: PJSIP/trunk-linhome-00000003 TSX State: Calling Inv State: EARLY [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:4533 handle_outgoing_response: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:3528 ast_sip_session_terminate: [Jun 7 13:48:23] DEBUG[570]: channel.c:2196 ast_channel_destructor: Channel 0x7f650c00d310 'PJSIP/trunk-linhome-00000003' destroying [Jun 7 13:48:23] DEBUG[570]: stasis.c:442 topic_dtor: Destroying topic. name: channel:1654602503.4, detail: [Jun 7 13:48:23] DEBUG[570]: stasis.c:451 topic_dtor: Topic 'channel:1654602503.4': 0x7f650c00b9a0 destroyed [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:680 ast_channel_nativeformats_set: : MultistreamFormats: (nothing) [Jun 7 13:48:23] DEBUG[570]: channel_internal_api.c:692 ast_channel_nativeformats_set: Channel is being initialized or destroyed [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2513 hangup: [Jun 7 13:48:23] DEBUG[552]: devicestate.c:466 do_state_change: Changing state for PJSIP/trunk-linhome - state 1 (Not in use) [Jun 7 13:48:23] DEBUG[560]: cdr.c:1473 cdr_object_finalize: Finalized CDR for PJSIP/trunk-linhome-00000003 - start 1654602503.287255 answer 0.000000 end 1654602503.523608 dur 0.236 bill 1654602503.523 dispo NO ANSWER [Jun 7 13:48:23] DEBUG[560]: cdr.c:1313 cdr_object_create_public_records: CDR for PJSIP/trunk-linhome-00000003 is dialed and has no Party B; discarding [Jun 7 13:48:23] DEBUG[639]: app_queue.c:2683 device_state_cb: Device 'PJSIP/trunk-linhome' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:4630 session_inv_on_state_changed: PJSIP/6000-00000002 Event: TSX_STATE Inv State: DISCONNCTD [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:4656 session_inv_on_state_changed: PJSIP/6000-00000002: Source of transaction state change is TX_MSG [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:4704 session_inv_on_state_changed: [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: PJSIP/6000-00000002 TSX State: Completed Inv State: DISCONNCTD [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:4770 session_inv_on_tsx_state_changed: Disconnected [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:4180 session_on_tsx_state: (null session) TSX State: Completed Inv State: DISCONNCTD [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[660]: chan_pjsip.c:2975 chan_pjsip_session_end: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:5821 set_format: Channel PJSIP/6000-00000002 setting write format path: ulaw -> ulaw [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:3207 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:2459 ast_softhangup_nolock: Soft-Hanging (0x10) up channel 'PJSIP/6000-00000002' [Jun 7 13:48:23] DEBUG[658][C-00000002]: channel.c:2549 ast_hangup: Channel 0x7f652c05b570 'PJSIP/6000-00000002' hanging up. Refs: 2 [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:2522 chan_pjsip_hangup: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[658][C-00000002]: chan_pjsip.c:2540 chan_pjsip_hangup: Cause: 503 [Jun 7 13:48:23] DEBUG[660]: chan_pjsip.c:2992 chan_pjsip_session_end: [Jun 7 13:48:23] DEBUG[660]: chan_pjsip.c:2489 hangup: PJSIP/6000-00000002 [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:3456 ast_sip_session_terminate: PJSIP/6000-00000002 Response 503 [Jun 7 13:48:23] DEBUG[660]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f652c092570) DTLS srtp - stopped timeout timer' [Jun 7 13:48:23] DEBUG[660]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f652c092570) DTLS srtp - stopped timeout timer' [Jun 7 13:48:23] DEBUG[660]: res_rtp_asterisk.c:2275 ast_rtp_dtls_stop: (0x7f652c092570) DTLS stop [Jun 7 13:48:23] DEBUG[660]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f652c092570) DTLS srtp - stopped timeout timer' [Jun 7 13:48:23] DEBUG[660]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f652c092570) DTLS srtp - stopped timeout timer' [Jun 7 13:48:23] DEBUG[660]: res_rtp_asterisk.c:3981 rtp_deallocate_transport: (0x7f652c092570) ICE RTP transport deallocating [Jun 7 13:48:23] DEBUG[660]: rtp_engine.c:455 instance_destructor: Destroyed RTP instance '0x7f652c092570' [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:3528 ast_sip_session_terminate: [Jun 7 13:48:23] DEBUG[660]: res_pjsip_session.c:2912 session_destructor: 6000: Destroying SIP session [Jun 7 13:48:23] DEBUG[660]: channel.c:2196 ast_channel_destructor: Channel 0x7f652c05b570 'PJSIP/6000-00000002' destroying [Jun 7 13:48:23] DEBUG[660]: stasis.c:442 topic_dtor: Destroying topic. name: channel:1654602503.3, detail: [Jun 7 13:48:23] DEBUG[660]: stasis.c:451 topic_dtor: Topic 'channel:1654602503.3': 0x7f652c025b70 destroyed [Jun 7 13:48:23] DEBUG[552]: devicestate.c:466 do_state_change: Changing state for PJSIP/6000 - state 5 (Unavailable) [Jun 7 13:48:23] DEBUG[639]: app_queue.c:2683 device_state_cb: Device 'PJSIP/6000' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Jun 7 13:48:23] DEBUG[660]: channel_internal_api.c:680 ast_channel_nativeformats_set: : MultistreamFormats: (nothing) [Jun 7 13:48:23] DEBUG[660]: channel_internal_api.c:692 ast_channel_nativeformats_set: Channel is being initialized or destroyed [Jun 7 13:48:23] DEBUG[660]: chan_pjsip.c:2513 hangup: [Jun 7 13:48:23] DEBUG[560]: stasis.c:580 stasis_topic_create_with_detail: Creating topic. name: channel:1654602503.5, detail: [Jun 7 13:48:23] DEBUG[560]: stasis.c:614 stasis_topic_create_with_detail: Topic 'channel:1654602503.5': 0x7f6504001e90 created [Jun 7 13:48:23] DEBUG[560]: stasis.c:442 topic_dtor: Destroying topic. name: channel:1654602503.5, detail: [Jun 7 13:48:23] DEBUG[560]: stasis.c:451 topic_dtor: Topic 'channel:1654602503.5': 0x7f6504001e90 destroyed [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c033b98 for Response msg 200/CANCEL/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/outsess/trunk-linhome-00000069 associated with dialog dlg0x7f652c033b98 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4203 session_on_rx_response: trunk-linhome Method: CANCEL Status: 200 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4206 session_on_rx_response: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: trunk-linhome TSX State: Completed Inv State: EARLY [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: trunk-linhome TSX State: Terminated Inv State: EARLY [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4936 session_inv_on_tsx_state_changed: Nothing delayed [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4180 session_on_tsx_state: trunk-linhome TSX State: Terminated Inv State: EARLY [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4184 session_on_tsx_state: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (ulaw|alaw)> [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c033b98 for Response msg 487/INVITE/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/outsess/trunk-linhome-00000069 associated with dialog dlg0x7f652c033b98 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4203 session_on_rx_response: trunk-linhome Method: INVITE Status: 487 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4206 session_on_rx_response: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4630 session_inv_on_state_changed: trunk-linhome Event: TSX_STATE Inv State: DISCONNCTD [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4656 session_inv_on_state_changed: trunk-linhome: Source of transaction state change is RX_MSG [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4598 handle_incoming_before_media: trunk-linhome: Received response [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4465 handle_incoming_response: trunk-linhome: Response is 487 Request Terminated [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3162 chan_pjsip_incoming_response_update_cause: trunk-linhome: Status: 487 [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:3165 chan_pjsip_incoming_response_update_cause: trunk-linhome: No channel [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4477 handle_incoming_response: trunk-linhome [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4704 session_inv_on_state_changed: [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: trunk-linhome TSX State: Completed Inv State: DISCONNCTD [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4770 session_inv_on_tsx_state_changed: Disconnected [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: (null session) TSX State: Completed Inv State: DISCONNCTD [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2975 chan_pjsip_session_end: trunk-linhome [Jun 7 13:48:23] DEBUG[570]: chan_pjsip.c:2978 chan_pjsip_session_end: No channel [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:2912 session_destructor: trunk-linhome: Destroying SIP session [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f652c04ca30) DTLS srtp - stopped timeout timer' [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f652c04ca30) DTLS srtp - stopped timeout timer' [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:2275 ast_rtp_dtls_stop: (0x7f652c04ca30) DTLS stop [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f652c04ca30) DTLS srtp - stopped timeout timer' [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7f652c04ca30) DTLS srtp - stopped timeout timer' [Jun 7 13:48:23] DEBUG[570]: res_rtp_asterisk.c:3981 rtp_deallocate_transport: (0x7f652c04ca30) ICE RTP transport deallocating [Jun 7 13:48:23] DEBUG[570]: rtp_engine.c:455 instance_destructor: Destroyed RTP instance '0x7f652c04ca30' [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: (null session) TSX State: Terminated Inv State: DISCONNCTD [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4760 session_inv_on_tsx_state_changed: Session ended [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4180 session_on_tsx_state: (null session) TSX State: Terminated Inv State: DISCONNCTD [Jun 7 13:48:23] DEBUG[569]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Response msg 487/INVITE/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:519 distributor: No dialog serializer for Response msg 487/INVITE/cseq=50 (rdata0x7f652c014458). Using request transaction as basis. [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:123 find_request_serializer: Could not find transaction for Response msg 487/INVITE/cseq=50 (rdata0x7f652c014458). [Jun 7 13:48:23] DEBUG[569]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-0000002f to use for Response msg 487/INVITE/cseq=50 (rdata0x7f652c014458) [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4203 session_on_rx_response: (null session) Method: INVITE Status: 487 [Jun 7 13:48:23] DEBUG[570]: res_pjsip_session.c:4206 session_on_rx_response: [Jun 7 13:48:24] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c010458 for Request msg ACK/cseq=21 (rdata0x7f65280016b8) [Jun 7 13:48:24] DEBUG[569]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000028 to use for Request msg ACK/cseq=21 (rdata0x7f65280016b8) [Jun 7 13:48:24] DEBUG[570]: res_pjsip_endpoint_identifier_ip.c:258 ip_identify_match_check: Source address 10.8.0.2:5060 does not match identify 'trunk-linhome-identify' [Jun 7 13:48:24] DEBUG[570]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username '6000' domain '192.168.0.17' [Jun 7 13:48:24] DEBUG[570]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username '6000' domain '192.168.0.17' [Jun 7 13:48:24] DEBUG[570]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: (null session) TSX State: Confirmed Inv State: DISCONNCTD [Jun 7 13:48:24] DEBUG[570]: res_pjsip_session.c:4760 session_inv_on_tsx_state_changed: Session ended [Jun 7 13:48:24] DEBUG[570]: res_pjsip_session.c:4180 session_on_tsx_state: (null session) TSX State: Confirmed Inv State: DISCONNCTD [Jun 7 13:48:24] DEBUG[570]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:24] DEBUG[569]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7f652c010458 for Request msg ACK/cseq=21 (rdata0x7f65280016b8) [Jun 7 13:48:24] DEBUG[569]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000028 to use for Request msg ACK/cseq=21 (rdata0x7f65280016b8) [Jun 7 13:48:24] DEBUG[570]: res_pjsip_endpoint_identifier_ip.c:258 ip_identify_match_check: Source address 10.8.0.2:5060 does not match identify 'trunk-linhome-identify' [Jun 7 13:48:24] DEBUG[570]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username '6000' domain '192.168.0.17' [Jun 7 13:48:24] DEBUG[570]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username '6000' domain '192.168.0.17' [Jun 7 13:48:29] DEBUG[569]: res_pjsip_session.c:4748 session_inv_on_tsx_state_changed: (null session) TSX State: Terminated Inv State: DISCONNCTD [Jun 7 13:48:29] DEBUG[569]: res_pjsip_session.c:4760 session_inv_on_tsx_state_changed: Session ended [Jun 7 13:48:29] DEBUG[569]: res_pjsip_session.c:4180 session_on_tsx_state: (null session) TSX State: Terminated Inv State: DISCONNCTD [Jun 7 13:48:29] DEBUG[569]: res_pjsip_session.c:4189 session_on_tsx_state: [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_options.c:927 sip_options_qualify_aor: Qualifying all contacts on AOR 'trunk-linhome-aor' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_options.c:856 sip_options_qualify_contact: Qualifying contact 'trunk-linhome-aor@@bb1a8aafc83faa0fac3112563ff5aec1' on AOR 'trunk-linhome-aor' [Jun 7 13:48:33] DEBUG[570]: res_pjsip.c:4808 endpt_send_request: 0x7f652c06d8b0: Wrapper created [Jun 7 13:48:33] DEBUG[570]: res_pjsip.c:4823 endpt_send_request: 0x7f652c06d8b0: Set timer to 3000 msec [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:475 sip_resolve: Performing SIP DNS resolution of target 'sip.linhome.org' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:502 sip_resolve: Transport type for target 'sip.linhome.org' is 'Unspecified' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:545 sip_resolve: [0x7f652c00ea38] Created resolution tracking for target 'sip.linhome.org' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c00ea38] Added target 'sip.linhome.org' with record type '35', transport 'Unspecified', and port '0' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c00ea38] Added target '_sips._tcp.sip.linhome.org' with record type '33', transport 'TLS transport', and port '5061' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c00ea38] Added target '_sip._tcp.sip.linhome.org' with record type '33', transport 'TCP transport', and port '5060' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c00ea38] Added target '_sip._udp.sip.linhome.org' with record type '33', transport 'UDP transport', and port '5060' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c00ea38] Added target 'sip.linhome.org' with record type '1', transport 'UDP transport', and port '5060' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:616 sip_resolve: [0x7f652c00ea38] Starting initial resolution using parallel queries for target 'sip.linhome.org' [Jun 7 13:48:33] DEBUG[554]: dns.c:555 ast_search_dns_ex: DNS search failed for sip.linhome.org [Jun 7 13:48:33] DEBUG[554]: dns_system_resolver.c:154 dns_system_resolver_process_query: DNS search failed for query: 'sip.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:273 sip_resolve_callback: [0x7f652c00ea38] All parallel queries completed [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c00ea38] SRV record received on target '_sips._tcp.sip.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c00ea38] Added target 'sip6.linhome.org' with record type '1', transport 'TLS transport', and port '5061' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c00ea38] SRV record received on target '_sips._tcp.sip.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c00ea38] Added target 'sip1.linhome.org' with record type '1', transport 'TLS transport', and port '5061' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c00ea38] SRV record received on target '_sip._tcp.sip.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c00ea38] Added target 'sip6.linhome.org' with record type '1', transport 'TCP transport', and port '5060' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c00ea38] SRV record received on target '_sip._tcp.sip.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c00ea38] Added target 'sip1.linhome.org' with record type '1', transport 'TCP transport', and port '5060' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c00ea38] SRV record received on target '_sip._udp.sip.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c00ea38] Added target 'sip6.linhome.org' with record type '1', transport 'UDP transport', and port '5060' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:345 sip_resolve_callback: [0x7f652c00ea38] SRV record received on target '_sip._udp.sip.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:174 sip_resolve_add: [0x7f652c00ea38] Added target 'sip1.linhome.org' with record type '1', transport 'UDP transport', and port '5060' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:307 sip_resolve_callback: [0x7f652c00ea38] A record being skipped on target 'sip.linhome.org' because NAPTR or SRV record exists [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:411 sip_resolve_callback: [0x7f652c00ea38] New queries added, performing parallel resolution again [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:273 sip_resolve_callback: [0x7f652c00ea38] All parallel queries completed [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c00ea38] A record received on target 'sip6.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c00ea38] A record received on target 'sip1.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c00ea38] A record received on target 'sip6.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c00ea38] A record received on target 'sip1.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c00ea38] A record received on target 'sip6.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:322 sip_resolve_callback: [0x7f652c00ea38] A record received on target 'sip1.linhome.org' [Jun 7 13:48:33] DEBUG[554]: res_pjsip/pjsip_resolver.c:417 sip_resolve_callback: [0x7f652c00ea38] Resolution completed - 6 viable targets [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c00ea38] Address '0' is 54.37.202.229:5061 with transport 'TLS transport' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c00ea38] Address '1' is 91.121.209.194:5061 with transport 'TLS transport' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c00ea38] Address '2' is 54.37.202.229:5060 with transport 'TCP transport' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c00ea38] Address '3' is 91.121.209.194:5060 with transport 'TCP transport' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c00ea38] Address '4' is 54.37.202.229:5060 with transport 'UDP transport' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:199 sip_resolve_invoke_user_callback: [0x7f652c00ea38] Address '5' is 91.121.209.194:5060 with transport 'UDP transport' [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_resolver.c:205 sip_resolve_invoke_user_callback: [0x7f652c00ea38] Invoking user callback with '6' addresses [Jun 7 13:48:33] DEBUG[569]: res_pjsip/pjsip_distributor.c:519 distributor: No dialog serializer for Response msg 407/OPTIONS/cseq=62281 (rdata0x7f652c014458). Using request transaction as basis. [Jun 7 13:48:33] DEBUG[569]: res_pjsip/pjsip_distributor.c:127 find_request_serializer: Found transaction tsx0x7f652c047ef8 for Response msg 407/OPTIONS/cseq=62281 (rdata0x7f652c014458). [Jun 7 13:48:33] DEBUG[569]: res_pjsip/pjsip_distributor.c:137 find_request_serializer: Found serializer pjsip/options/trunk-linhome-aor-00000044 on transaction tsx0x7f652c047ef8 [Jun 7 13:48:33] DEBUG[570]: res_pjsip.c:4686 endpt_send_request_cb: 0x7f652c06d8b0: PJSIP tsx response received [Jun 7 13:48:33] DEBUG[570]: res_pjsip.c:4699 endpt_send_request_cb: 0x7f652c06d8b0: Cancelling timer [Jun 7 13:48:33] DEBUG[570]: res_pjsip.c:4708 endpt_send_request_cb: 0x7f652c06d8b0: Timer cancelled [Jun 7 13:48:33] DEBUG[570]: res_pjsip_outbound_authenticator_digest.c:210 set_outbound_authentication_credentials: Skipping header with realm 'sip.linhome.org' and unsupported 'SHA-256' algorithm [Jun 7 13:48:33] DEBUG[570]: res_pjsip_outbound_authenticator_digest.c:227 set_outbound_authentication_credentials: Searching auths to find matching ones for header with realm 'sip.linhome.org' and algorithm 'MD5' [Jun 7 13:48:33] DEBUG[570]: res_pjsip_outbound_authenticator_digest.c:271 set_outbound_authentication_credentials: Found wildcard auth 'trunk-linhome-auth' for realm 'sip.linhome.org' [Jun 7 13:48:33] DEBUG[570]: res_pjsip_outbound_authenticator_digest.c:301 set_outbound_authentication_credentials: Using wildcard auth 'trunk-linhome-auth' for realm 'sip.linhome.org' [Jun 7 13:48:33] DEBUG[570]: res_pjsip_outbound_authenticator_digest.c:387 set_outbound_authentication_credentials: Set 1 credentials in auth session [Jun 7 13:48:33] DEBUG[570]: res_pjsip.c:4808 endpt_send_request: 0x7f652c0323d0: Wrapper created [Jun 7 13:48:33] DEBUG[570]: res_pjsip.c:4729 endpt_send_request_cb: 0x7f652c06d8b0: Callbacks executed [Jun 7 13:48:33] DEBUG[570]: res_pjsip.c:4785 send_request_wrapper_destructor: 0x7f652c06d8b0: wrapper destroyed [Jun 7 13:48:33] DEBUG[569]: res_pjsip/pjsip_distributor.c:519 distributor: No dialog serializer for Response msg 403/OPTIONS/cseq=62282 (rdata0x7f652c014458). Using request transaction as basis. [Jun 7 13:48:33] DEBUG[569]: res_pjsip/pjsip_distributor.c:127 find_request_serializer: Found transaction tsx0x7f652c010458 for Response msg 403/OPTIONS/cseq=62282 (rdata0x7f652c014458). [Jun 7 13:48:33] DEBUG[569]: res_pjsip/pjsip_distributor.c:137 find_request_serializer: Found serializer pjsip/options/trunk-linhome-aor-00000044 on transaction tsx0x7f652c010458 [Jun 7 13:48:33] DEBUG[570]: res_pjsip.c:4686 endpt_send_request_cb: 0x7f652c0323d0: PJSIP tsx response received [Jun 7 13:48:33] DEBUG[570]: res_pjsip.c:4729 endpt_send_request_cb: 0x7f652c0323d0: Callbacks executed [Jun 7 13:48:33] DEBUG[570]: res_pjsip.c:4785 send_request_wrapper_destructor: 0x7f652c0323d0: wrapper destroyed [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_options.c:755 sip_options_contact_status_notify_task: Contact trunk-linhome-aor/sip:sip.linhome.org status didn't change: Reachable, RTT: 79.016 msec [Jun 7 13:48:33] DEBUG[570]: res_pjsip/pjsip_options.c:775 sip_options_contact_status_notify_task: AOR 'trunk-linhome-aor' now has 1 available contacts [Jun 7 13:48:43] DEBUG[657]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying. [Jun 7 13:48:43] DEBUG[540]: threadpool.c:1029 worker_thread_destroy: Destroying worker thread 19 [Jun 7 13:48:43] DEBUG[659]: threadpool.c:1169 worker_idle: Worker thread idle timeout reached. Dying. [Jun 7 13:48:43] DEBUG[540]: threadpool.c:1029 worker_thread_destroy: Destroying worker thread 20