[SOLVED ] Basic SIP configuration - registration ok - Nothing happens

lmon · October 15, 2021, 12:14pm

Hi,
I’m installing a new test FreePBX instance for demo purposes. I was a little bit too enthusiastic and rolled on the “old” configuration., which is not working .
System : Ubuntu 20 - Asterisk 18.7.1 - FreePBX 15.0.17.55
I’m then back to basics to first have a very light config working.
Here is where am I so far
I need 2 clients / extensions connect to each other , so
created 2 extentions :

Configured my SIP settings :

blured is my public Server IP address

Please note I’m using custom ports :

I can get my SIP client registered, but trying to get as exemple the extension number told ( with * 65 ) , no sound and 503 Error.

Here is the debug from the Asterisk console, I see a lot of warnings but nothing clear to me. any insights ? ( W.X.Y.Z being client public IP and A.B.C.D being Server public IP )

Thanks !

  DEBUG[24381]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg INVITE/cseq=1 (rdata0x7ff468002928)
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000034 to use for Request msg INVITE/cseq=1 (rdata0x7ff468002928)
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[49340]: res_pjsip_endpoint_identifier_ip.c:275 common_identify: No identify sections to match against
  DEBUG[49340]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username '1234' domain 'A.B.C.D'
  DEBUG[49340]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username '1234' domain 'A.B.C.D'
  DEBUG[49340]: res_pjsip_authenticator_digest.c:470 digest_check_auth: Using default realm 'asterisk' on incoming auth '1234-auth'.
  DEBUG[49340]: res_pjsip_authenticator_digest.c:357 verify: Realm: asterisk  Username: 1234  Result: NOAUTH
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '172.31.17.207' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '172.31.17.207' and port ''.
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg INVITE/cseq=1 (rdata0x7ff468002928)
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000034 to use for Request msg INVITE/cseq=1 (rdata0x7ff468002928)
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[49340]: res_pjsip_endpoint_identifier_ip.c:275 common_identify: No identify sections to match against
  DEBUG[49340]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username '1234' domain 'A.B.C.D'
  DEBUG[49340]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username '1234' domain 'A.B.C.D'
  DEBUG[49340]: res_pjsip_authenticator_digest.c:470 digest_check_auth: Using default realm 'asterisk' on incoming auth '1234-auth'.
  DEBUG[49340]: res_pjsip_authenticator_digest.c:357 verify: Realm: asterisk  Username: 1234  Result: NOAUTH
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '172.31.17.207' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '172.31.17.207' and port ''.
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg ACK/cseq=1 (rdata0x7ff468002928)
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000034 to use for Request msg ACK/cseq=1 (rdata0x7ff468002928)
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[49340]: res_pjsip_endpoint_identifier_ip.c:275 common_identify: No identify sections to match against
  DEBUG[49340]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username '1234' domain 'A.B.C.D'
  DEBUG[49340]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username '1234' domain 'A.B.C.D'
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg INVITE/cseq=2 (rdata0x7ff468002928)
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000034 to use for Request msg INVITE/cseq=2 (rdata0x7ff468002928)
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[49340]: res_pjsip_endpoint_identifier_ip.c:275 common_identify: No identify sections to match against
  DEBUG[49340]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username '1234' domain 'A.B.C.D'
  DEBUG[49340]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username '1234' domain 'A.B.C.D'
  DEBUG[49340]: res_pjsip_authenticator_digest.c:470 digest_check_auth: Using default realm 'asterisk' on incoming auth '1234-auth'.
  DEBUG[49340]: res_pjsip_authenticator_digest.c:260 check_nonce: Calculated nonce 1634298640/90bc44322ee42b65f3c0c9fb55494fdf. Actual nonce is 1634298640/90bc44322ee42b65f3c0c9fb55494fdf
  DEBUG[49340]: res_pjsip_authenticator_digest.c:357 verify: Realm: asterisk  Username: 1234  Result: SUCCESS
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '172.31.17.207' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '172.31.17.207' and port ''.
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[49340]: res_pjsip_session.c:4224 session_on_rx_request:  (null session) Request: INVITE
  DEBUG[49340]: res_pjsip_session.c:4059 handle_new_invite_request:  Request:
  DEBUG[49340]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000034 to use for Request msg INVITE/cseq=2 (rdata0x7ff46803f818)
  DEBUG[49340]: chan_pjsip.c:2954 chan_pjsip_session_begin:  1234
  DEBUG[49340]: chan_pjsip.c:2958 chan_pjsip_session_begin:  Direct media no glare mitigation
  DEBUG[49340]: res_pjsip_session.c:3918 new_invite:  1234
  DEBUG[49340]: res_pjsip_session.c:3998 new_invite:  1234: Call (UDP:W.X.Y.Z:24960) to extension '*65' sending 100 Trying
  DEBUG[49340]: res_pjsip_session.c:4503 handle_outgoing_response:  1234: Method is INVITE, Response is 100 Trying
  DEBUG[49340]: res_pjsip_session.c:4522 handle_outgoing_response:  1234
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[49340]: res_pjsip_session.c:4619 session_inv_on_state_changed:  1234 Event: TSX_STATE  Inv State: INCOMING
  DEBUG[49340]: res_pjsip_session.c:4357 __print_debug_details: Function session_inv_on_state_changed called on event TSX_STATE
  DEBUG[49340]: res_pjsip_session.c:4371 __print_debug_details: The state change pertains to the endpoint '1234()'
  DEBUG[49340]: res_pjsip_session.c:4376 __print_debug_details: The inv session still has an invite_tsx (0x7ff474033968)
  DEBUG[49340]: res_pjsip_session.c:4391 __print_debug_details: There is no transaction involved in this state change
  DEBUG[49340]: res_pjsip_session.c:4393 __print_debug_details: The current inv state is INCOMING
  DEBUG[49340]: res_pjsip_session.c:4645 session_inv_on_state_changed: 1234: Source of transaction state change is TX_MSG
  DEBUG[49340]: res_pjsip_session.c:4693 session_inv_on_state_changed:
  DEBUG[49340]: res_pjsip_session.c:4737 session_inv_on_tsx_state_changed:  1234 TSX State: Proceeding  Inv State: INCOMING
  DEBUG[49340]: res_pjsip_session.c:4357 __print_debug_details: Function session_inv_on_tsx_state_changed called on event TSX_STATE
  DEBUG[49340]: res_pjsip_session.c:4371 __print_debug_details: The state change pertains to the endpoint '1234()'
  DEBUG[49340]: res_pjsip_session.c:4376 __print_debug_details: The inv session still has an invite_tsx (0x7ff474033968)
  DEBUG[49340]: res_pjsip_session.c:4382 __print_debug_details: The UAS INVITE transaction involved in this state change is 0x7ff474033968
  DEBUG[49340]: res_pjsip_session.c:4386 __print_debug_details: The current transaction state is Proceeding
  DEBUG[49340]: res_pjsip_session.c:4388 __print_debug_details: The transaction state change event is TX_MSG
  DEBUG[49340]: res_pjsip_session.c:4393 __print_debug_details: The current inv state is INCOMING
  DEBUG[49340]: res_pjsip_session.c:4925 session_inv_on_tsx_state_changed:  Nothing delayed
  DEBUG[49340]: res_pjsip_session.c:4169 session_on_tsx_state:  1234 TSX State: Proceeding  Inv State: INCOMING
  DEBUG[49340]: res_pjsip_session.c:4173 session_on_tsx_state:  Topology: Pending: (null topology)  Active: (null topology)
  DEBUG[49340]: res_pjsip_session.c:4178 session_on_tsx_state:
  DEBUG[49340]: res_pjsip_session.c:769 handle_incoming_sdp:  1234: Media count: 1
  DEBUG[49340]: res_pjsip_session.c:795 handle_incoming_sdp:  1234: Processing stream 0
  DEBUG[49340]: res_pjsip_session.c:832 handle_incoming_sdp:  1234: Using audio-0 for new stream name
  DEBUG[49340]: res_pjsip_session.c:876 handle_incoming_sdp:  1234: Using new stream 0:audio-0:audio:sendrecv (nothing)
  DEBUG[49340]: res_pjsip_session.c:495 ast_sip_session_media_state_add:  1234 Adding position 0
  DEBUG[49340]: res_pjsip_session.c:541 ast_sip_session_media_state_add:  Creating new media session
  DEBUG[49340]: res_pjsip_session.c:584 ast_sip_session_media_state_add:  Setting media session as default for audio
  DEBUG[49340]: res_pjsip_session.c:589 ast_sip_session_media_state_add:  Done
  DEBUG[49340]: res_pjsip_session.c:929 handle_incoming_sdp:  1234: Negotiating incoming SDP media stream 0:audio-0:audio:sendrecv (nothing) using audio SDP handler
  DEBUG[49340]: res_pjsip_sdp_rtp.c:1497 negotiate_incoming_sdp_stream:  1234
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '192.168.1.35' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '192.168.1.35' and port ''.
  DEBUG[49340]: rtp_engine.c:526 ast_rtp_instance_new: Using engine 'asterisk' for RTP instance '0x7ff44c022d10'
  DEBUG[49340]: res_rtp_asterisk.c:3872 rtp_allocate_transport: (0x7ff44c022d10) RTP allocated port 26000
  DEBUG[49340]: res_rtp_asterisk.c:3902 rtp_allocate_transport: (0x7ff44c022d10) ICE creating session [::]:26000 (26000)
  DEBUG[49340]: res_rtp_asterisk.c:3784 ice_create: (0x7ff44c022d10) ICE create
  DEBUG[49340]: res_rtp_asterisk.c:3561 rtp_add_candidates_to_ice: (0x7ff44c022d10) ICE add system candidates
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '172.31.17.207' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '172.31.17.207' and port ''.
  DEBUG[49340]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7ff44c022d10) ICE add candidate: 172.31.17.207:26000, 2130706431
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'fe80::b7:dbff:fe82:5f80' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'fe80::b7:dbff:fe82:5f80' and port ''.
  DEBUG[49340]: res_rtp_asterisk.c:1329 ast_rtp_ice_add_cand: (0x7ff44c022d10) ICE add candidate: [fe80::b7:dbff:fe82:5f80]:26000, 2130706431
  DEBUG[49340]: rtp_engine.c:543 ast_rtp_instance_new: RTP instance '0x7ff44c022d10' is setup and ready to go
  DEBUG[49340]: res_rtp_asterisk.c:918 ast_rtp_ice_stop: (0x7ff44c022d10) ICE stopped
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'ip-172-31-17-207' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'ip-172-31-17-207' and port ''.
  DEBUG[49340]: res_rtp_asterisk.c:8433 ast_rtp_prop_set: (0x7ff44c022d10) RTCP setup on RTP instance
  DEBUG[49340]: res_pjsip_sdp_rtp.c:446 set_incoming_call_offer_cap:  1234
  DEBUG[49340]: res_pjsip_sdp_rtp.c:328 get_codecs:  1234
  DEBUG[49340]: rtp_engine.c:1318 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 9 based on m type on 0x7ff4398002a0
  DEBUG[49340]: rtp_engine.c:1318 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 0 based on m type on 0x7ff4398002a0
  DEBUG[49340]: rtp_engine.c:1318 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 8 based on m type on 0x7ff4398002a0
  DEBUG[49340]: rtp_engine.c:1318 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 3 based on m type on 0x7ff4398002a0
  DEBUG[49340]: res_pjsip_sdp_rtp.c:404 get_codecs:
  DEBUG[49340]: res_pjsip_session/pjsip_session_caps.c:161 ast_sip_session_create_joint_call_cap: '1234' Caps for incoming audio call with pref 'local' - remote: (ulaw|gsm|alaw|g722|ilbc|opus) local: (ulaw|alaw|gsm|g726|g722|testlaw) joint: (ulaw|alaw|gsm|g722)
  DEBUG[49340]: rtp_engine.c:1282 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 0 (0x7ff44c015d58) from 0x7ff4398002a0 to 0x7ff4398002a0
  DEBUG[49340]: rtp_engine.c:1282 ast_rtp_codecs_payloads_xover: Crossover copying tx to rx payload mapping 3 (0x7ff44c0258e8) from 0x7ff4398002a0 to 0x7ff4398002a0
[ CUT ]
  DEBUG[49340]: res_pjsip_sdp_rtp.c:482 set_incoming_call_offer_cap:
  DEBUG[49340]: res_pjsip_sdp_rtp.c:1587 negotiate_incoming_sdp_stream:
  DEBUG[49340]: res_pjsip_session.c:948 handle_incoming_sdp:  1234: Media stream 0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722) handled by audio
  DEBUG[49340]: res_pjsip_session.c:955 handle_incoming_sdp:  1234: Done with stream 0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722)
  DEBUG[49340]: res_pjsip_session.c:960 handle_incoming_sdp:  1234: Handled? yes
  DEBUG[49340]: res_pjsip_session.c:5089 create_local_sdp:  1234
  DEBUG[49340]: res_pjsip_session.c:5126 create_local_sdp:  1234: Processing streams
  DEBUG[49340]: res_pjsip_session.c:5132 create_local_sdp:  1234: Processing stream 0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722)
  DEBUG[49340]: res_pjsip_session.c:495 ast_sip_session_media_state_add:  1234 Adding position 0
  DEBUG[49340]: res_pjsip_session.c:503 ast_sip_session_media_state_add:  Using existing media_session
  DEBUG[49340]: res_pjsip_session.c:4965 add_sdp_streams:  1234 Stream: 0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722)
  DEBUG[49340]: res_pjsip_sdp_rtp.c:1742 create_outgoing_sdp_stream:  1234 Type: audio 0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722)
  DEBUG[49340]: res_rtp_asterisk.c:8332 ast_rtp_prop_set: (0x7ff44c022d10) RTCP ignoring duplicate property
  DEBUG[49340]: res_pjsip_sdp_rtp.c:2027 create_outgoing_sdp_stream:  RC: 1
  DEBUG[49340]: res_pjsip_session.c:4974 add_sdp_streams:  Had handler
  DEBUG[49340]: res_pjsip_session.c:5164 create_local_sdp:  1234: Stream 0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722) added
  DEBUG[49340]: res_pjsip_session.c:5177 create_local_sdp:  1234: Done with 0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722)
  DEBUG[49340]: res_pjsip_session.c:5183 create_local_sdp:  1234: Adding bundle groups (if available)
  DEBUG[49340]: res_pjsip_session.c:5189 create_local_sdp:  1234: Copying connection details
  DEBUG[49340]: res_pjsip_session.c:5192 create_local_sdp:  1234: Processing media 0
  DEBUG[49340]: res_pjsip_session.c:5210 create_local_sdp:  1234: Media 0 reset
  DEBUG[49340]: res_pjsip_session.c:5233 create_local_sdp:  1234
  DEBUG[49340]: res_pjsip_session.c:4402 handle_incoming_request:  1234: Method is INVITE
  DEBUG[49340]: chan_pjsip.c:3013 chan_pjsip_incoming_request:  1234
  DEBUG[49340]: chan_pjsip.c:555 chan_pjsip_new:  1234
  DEBUG[49340]: channel_internal_api.c:680 ast_channel_nativeformats_set:  <initializing>: Formats: (none)
  DEBUG[49340]: channel_internal_api.c:692 ast_channel_nativeformats_set:  Channel is being initialized or destroyed
  DEBUG[49340]: stasis.c:579 stasis_topic_create_with_detail: Creating topic. name: channel:1634298640.17, detail:
  DEBUG[49340]: stasis.c:613 stasis_topic_create_with_detail: Topic 'channel:1634298640.17': 0x7ff44c0256c0 created
  DEBUG[49340]: channel.c:951 __ast_channel_alloc_ap: Channel 0x7ff44c059230 'PJSIP/1234-00000011' allocated
  DEBUG[49340]: chan_pjsip.c:530 compatible_formats_exist:  Topology:  <0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722)> Formats: (ulaw|alaw|gsm|g726|g722|testlaw)
  DEBUG[49340]: chan_pjsip.c:543 compatible_formats_exist:  Compatible? yes
  DEBUG[49340]: channel_internal_api.c:680 ast_channel_nativeformats_set:  PJSIP/1234-00000011: MultistreamFormats: (ulaw|alaw|gsm|g722)
  DEBUG[49340]: channel_internal_api.c:702 ast_channel_nativeformats_set:  Set native formats but not topology
  DEBUG[49340]: channel_internal_api.c:1595 ast_channel_set_stream_topology:  PJSIP/1234-00000011:  <0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722)>
  DEBUG[49340]: channel_internal_api.c:1616 ast_channel_set_stream_topology:  Used provided topology
  DEBUG[49340]: chan_pjsip.c:675 chan_pjsip_new:
  DEBUG[49340]: chan_pjsip.c:3063 chan_pjsip_incoming_request:  PJSIP/1234-00000011
  DEBUG[49340]: chan_pjsip.c:3119 pbx_start_incoming_request:  PJSIP/1234-00000011
  DEBUG[49340]: chan_pjsip.c:3145 pbx_start_incoming_request: Started PBX on new PJSIP channel PJSIP/1234-00000011
  DEBUG[49340]: chan_pjsip.c:3147 pbx_start_incoming_request:  RC: 0
  DEBUG[49340]: res_pjsip_session.c:4412 handle_incoming_request:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip_session.c:4047 new_invite:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip_session.c:4125 handle_new_invite_request:  Request:  Session: PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip_session.c:4243 session_on_rx_request:  (null session) Handled request INVITE  ? yes
  DEBUG[24351]: threadpool.c:535 grow: Increasing threadpool stasis/pool's size by 1
  DEBUG[73441][C-00000012]: pbx.c:2938 pbx_extension_helper: Launching 'Set'
  DEBUG[73441][C-00000012]: pbx.c:2938 pbx_extension_helper: Launching 'Set'
  DEBUG[73441][C-00000012]: pbx.c:2938 pbx_extension_helper: Launching 'Set'
  DEBUG[73441][C-00000012]: pbx.c:2938 pbx_extension_helper: Launching 'Answer'
  DEBUG[73441][C-00000012]: chan_pjsip.c:733 chan_pjsip_answer:  PJSIP/1234-00000011
  DEBUG[24363]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for PJSIP - 1234
  DEBUG[24363]: devicestate.c:466 do_state_change: Changing state for PJSIP/1234 - state 2 (In use)
  DEBUG[24443]: app_queue.c:2586 device_state_cb: Device 'PJSIP/1234' changed to state '2' (In use) but we don't care because they're not a member of any queue.
  DEBUG[49340]: chan_pjsip.c:689 answer:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip_session.c:5338 session_inv_on_media_update:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip_session.c:1068 handle_negotiated_sdp:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip_session.c:974 handle_negotiated_sdp_session_media:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip_session.c:1005 handle_negotiated_sdp_session_media: PJSIP/1234-00000011: Applying negotiated SDP media stream 'audio' using audio SDP handler
  DEBUG[49340]: res_pjsip_sdp_rtp.c:2085 apply_negotiated_sdp_stream:  PJSIP/1234-00000011 Stream: 0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722)
  DEBUG[49340]: res_rtp_asterisk.c:8332 ast_rtp_prop_set: (0x7ff44c022d10) RTCP ignoring duplicate property
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '192.168.1.35' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '192.168.1.35' and port ''.
  DEBUG[49340]: acl.c:1045 ast_ouraddrfor: For destination '192.168.1.35', our source address is '172.31.17.207'.
  DEBUG[49340]: res_rtp_asterisk.c:8535 ast_rtp_remote_address_set: (0x7ff44c022d10) RTCP setting address on RTP instance
  DEBUG[49340]: res_pjsip_sdp_rtp.c:500 set_caps:  PJSIP/1234-00000011 ANSWER
  DEBUG[49340]: res_pjsip_sdp_rtp.c:328 get_codecs:  PJSIP/1234-00000011
  DEBUG[49340]: rtp_engine.c:1318 ast_rtp_codecs_payloads_set_m_type: Setting tx payload type 9 based on m type on 0x7ff439800160

[CUT]

lmon · October 15, 2021, 12:14pm

end of the logs :

DEBUG[49340]: channel_internal_api.c:680 ast_channel_nativeformats_set:  PJSIP/1234-00000011: MultistreamFormats: (ulaw)
  DEBUG[49340]: channel_internal_api.c:702 ast_channel_nativeformats_set:  Set native formats but not topology
  DEBUG[49340]: channel.c:5748 set_format: Channel PJSIP/1234-00000011 setting read format path: ulaw -> ulaw
  DEBUG[49340]: channel.c:5748 set_format: Channel PJSIP/1234-00000011 setting write format path: ulaw -> ulaw
  DEBUG[49340]: res_pjsip_sdp_rtp.c:611 set_caps:
  DEBUG[49340]: res_rtp_asterisk.c:9112 ast_rtp_activate: (0x7ff44c022d10) DTLS - ast_rtp_activate rtp=0x7ff44c04c620 - setup and perform DTLS'
  DEBUG[49340]: res_rtp_asterisk.c:2548 dtls_perform_handshake: (0x7ff44c04c620) DTLS perform handshake - ssl = (nil), setup = 0
  DEBUG[49340]: res_rtp_asterisk.c:2548 dtls_perform_handshake: (0x7ff44c04c620) DTLS perform handshake - ssl = (nil), setup = 0
  DEBUG[49340]: res_pjsip_sdp_rtp.c:2234 apply_negotiated_sdp_stream:  Handled
  DEBUG[49340]: res_pjsip_session.c:1010 handle_negotiated_sdp_session_media: PJSIP/1234-00000011: Applied negotiated SDP media stream 'audio' using audio SDP handler
  DEBUG[49340]: res_pjsip_session.c:1013 handle_negotiated_sdp_session_media:  PJSIP/1234-00000011: Applied negotiated SDP media stream 'audio' using audio SDP handler
  DEBUG[49340]: channel_internal_api.c:1595 ast_channel_set_stream_topology:  PJSIP/1234-00000011:  <0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722)>
  DEBUG[49340]: channel_internal_api.c:1616 ast_channel_set_stream_topology:  Used provided topology
  DEBUG[49340]: res_pjsip_session.c:1223 handle_negotiated_sdp:
  DEBUG[49340]: res_pjsip_session.c:5402 session_inv_on_media_update:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip_session.c:4503 handle_outgoing_response:  PJSIP/1234-00000011: Method is INVITE, Response is 200 OK
  DEBUG[49340]: res_pjsip_session.c:4522 handle_outgoing_response:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip/pjsip_message_filter.c:296 filter_on_tx_message: Re-wrote Contact URI host/port to 172.31.17.207:5960 (this may be re-written again later)
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting '172.31.17.207' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host '172.31.17.207' and port ''.
  DEBUG[49340]: res_pjsip_session.c:5498 session_outgoing_nat_hook: (null session): Setting external media address to A.B.C.D
  DEBUG[49340]: res_pjsip_session.c:4619 session_inv_on_state_changed:  PJSIP/1234-00000011 Event: TSX_STATE  Inv State: CONNECTING
  DEBUG[49340]: res_pjsip_session.c:4357 __print_debug_details: Function session_inv_on_state_changed called on event TSX_STATE
  DEBUG[49340]: res_pjsip_session.c:4371 __print_debug_details: The state change pertains to the endpoint '1234(PJSIP/1234-00000011)'
  DEBUG[49340]: res_pjsip_session.c:4376 __print_debug_details: The inv session still has an invite_tsx (0x7ff474033968)
  DEBUG[49340]: res_pjsip_session.c:4391 __print_debug_details: There is no transaction involved in this state change
  DEBUG[49340]: res_pjsip_session.c:4393 __print_debug_details: The current inv state is CONNECTING
  DEBUG[49340]: res_pjsip_session.c:4645 session_inv_on_state_changed: PJSIP/1234-00000011: Source of transaction state change is TX_MSG
  DEBUG[49340]: res_pjsip_session.c:4693 session_inv_on_state_changed:
  DEBUG[49340]: res_pjsip_session.c:4737 session_inv_on_tsx_state_changed:  PJSIP/1234-00000011 TSX State: Completed  Inv State: CONNECTING
  DEBUG[49340]: res_pjsip_session.c:4357 __print_debug_details: Function session_inv_on_tsx_state_changed called on event TSX_STATE
  DEBUG[49340]: res_pjsip_session.c:4371 __print_debug_details: The state change pertains to the endpoint '1234(PJSIP/1234-00000011)'
  DEBUG[49340]: res_pjsip_session.c:4376 __print_debug_details: The inv session still has an invite_tsx (0x7ff474033968)
  DEBUG[49340]: res_pjsip_session.c:4382 __print_debug_details: The UAS INVITE transaction involved in this state change is 0x7ff474033968
  DEBUG[49340]: res_pjsip_session.c:4386 __print_debug_details: The current transaction state is Completed
  DEBUG[49340]: res_pjsip_session.c:4388 __print_debug_details: The transaction state change event is TX_MSG
  DEBUG[49340]: res_pjsip_session.c:4393 __print_debug_details: The current inv state is CONNECTING
  DEBUG[49340]: res_pjsip_session.c:4925 session_inv_on_tsx_state_changed:  Nothing delayed
  DEBUG[49340]: res_pjsip_session.c:4169 session_on_tsx_state:  PJSIP/1234-00000011 TSX State: Completed  Inv State: CONNECTING
  DEBUG[49340]: res_pjsip_session.c:4173 session_on_tsx_state:  Topology: Pending: (null topology)  Active:  <0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722)>
  DEBUG[49340]: res_pjsip_session.c:4178 session_on_tsx_state:
  DEBUG[49340]: chan_pjsip.c:723 answer:
  DEBUG[73441][C-00000012]: chan_pjsip.c:762 chan_pjsip_answer:
  DEBUG[73441][C-00000012]: chan_pjsip.c:1632 chan_pjsip_indicate:  PJSIP/1234-00000011: Indicated Stop generators
  DEBUG[73441][C-00000012]: chan_pjsip.c:1843 chan_pjsip_indicate:  PJSIP/1234-00000011
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:393 find_dialog: Could not find matching transaction for Request msg ACK/cseq=1 (rdata0x7ff468002928)
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:471 ast_sip_get_distributor_serializer: Calculated serializer pjsip/distributor-00000034 to use for Request msg ACK/cseq=1 (rdata0x7ff468002928)
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[49340]: res_pjsip_endpoint_identifier_ip.c:275 common_identify: No identify sections to match against
  DEBUG[49340]: res_pjsip_endpoint_identifier_user.c:148 username_identify: Attempting identify by From username '1234' domain 'A.B.C.D'
  DEBUG[49340]: res_pjsip_endpoint_identifier_user.c:160 username_identify: Identified by From username '1234' domain 'A.B.C.D'
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7ff47400f4c8 for Request msg ACK/cseq=2 (rdata0x7ff468002928)
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/distributor-00000034 associated with dialog dlg0x7ff47400f4c8
  DEBUG[49340]: res_pjsip_session.c:4737 session_inv_on_tsx_state_changed:  PJSIP/1234-00000011 TSX State: Terminated  Inv State: CONNECTING
  DEBUG[49340]: res_pjsip_session.c:4357 __print_debug_details: Function session_inv_on_tsx_state_changed called on event TSX_STATE
  DEBUG[49340]: res_pjsip_session.c:4371 __print_debug_details: The state change pertains to the endpoint '1234(PJSIP/1234-00000011)'
  DEBUG[49340]: res_pjsip_session.c:4379 __print_debug_details: The inv session does NOT have an invite_tsx
  DEBUG[49340]: res_pjsip_session.c:4382 __print_debug_details: The UAS INVITE transaction involved in this state change is 0x7ff474033968
  DEBUG[49340]: res_pjsip_session.c:4386 __print_debug_details: The current transaction state is Terminated
  DEBUG[49340]: res_pjsip_session.c:4388 __print_debug_details: The transaction state change event is USER
  DEBUG[49340]: res_pjsip_session.c:4393 __print_debug_details: The current inv state is CONNECTING
  DEBUG[49340]: res_pjsip_session.c:4925 session_inv_on_tsx_state_changed:  Nothing delayed
  DEBUG[49340]: res_pjsip_session.c:4169 session_on_tsx_state:  PJSIP/1234-00000011 TSX State: Terminated  Inv State: CONNECTING
  DEBUG[49340]: res_pjsip_session.c:4173 session_on_tsx_state:  Topology: Pending: (null topology)  Active:  <0:audio-0:audio:sendrecv (ulaw|alaw|gsm|g722)>
  DEBUG[49340]: res_pjsip_session.c:4178 session_on_tsx_state:
  DEBUG[49340]: res_pjsip_session.c:4619 session_inv_on_state_changed:  PJSIP/1234-00000011 Event: RX_MSG  Inv State: CONFIRMED
  DEBUG[49340]: res_pjsip_session.c:4357 __print_debug_details: Function session_inv_on_state_changed called on event RX_MSG
  DEBUG[49340]: res_pjsip_session.c:4371 __print_debug_details: The state change pertains to the endpoint '1234(PJSIP/1234-00000011)'
  DEBUG[49340]: res_pjsip_session.c:4379 __print_debug_details: The inv session does NOT have an invite_tsx
  DEBUG[49340]: res_pjsip_session.c:4391 __print_debug_details: There is no transaction involved in this state change
  DEBUG[49340]: res_pjsip_session.c:4393 __print_debug_details: The current inv state is CONFIRMED
  DEBUG[49340]: res_pjsip_session.c:4587 handle_incoming_before_media: PJSIP/1234-00000011: Received request
  DEBUG[49340]: res_pjsip_session.c:4402 handle_incoming_request:  PJSIP/1234-00000011: Method is ACK
  DEBUG[49340]: chan_pjsip.c:3244 chan_pjsip_incoming_ack:  PJSIP/1234-00000011
  DEBUG[49340]: chan_pjsip.c:3248 chan_pjsip_incoming_ack:  PJSIP/1234-00000011: Queueing SRCCHANGE
  DEBUG[49340]: chan_pjsip.c:3252 chan_pjsip_incoming_ack:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip_session.c:4412 handle_incoming_request:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip_session.c:4693 session_inv_on_state_changed:
  DEBUG[49340]: res_pjsip_session.c:4224 session_on_rx_request:  PJSIP/1234-00000011 Request: ACK
  DEBUG[49340]: res_pjsip_session.c:4243 session_on_rx_request:  PJSIP/1234-00000011 Handled request ACK  ? yes
  DEBUG[73441][C-00000012]: channel.c:2737 __ast_answer: Didn't receive a media frame from PJSIP/1234-00000011 within 500 ms of answering. Continuing anyway
  DEBUG[73441][C-00000012]: pbx.c:2938 pbx_extension_helper: Launching 'Wait'
  WARNING[73441][C-00000012]: pbx.c:2927 pbx_extension_helper: No application 'Macro' for extension (from-internal, *65, 6)
  DEBUG[73441][C-00000012]: pbx.c:4441 __ast_pbx_run: Spawn extension (from-internal,*65,6) exited non-zero on 'PJSIP/1234-00000011'
  DEBUG[73441][C-00000012]: channel.c:2461 ast_softhangup_nolock: Soft-Hanging (0x10) up channel 'PJSIP/1234-00000011'
  DEBUG[73441][C-00000012]: channel.c:2461 ast_softhangup_nolock: Soft-Hanging (0x80) up channel 'PJSIP/1234-00000011'
  WARNING[73441][C-00000012]: pbx.c:2927 pbx_extension_helper: No application 'Macro' for extension (from-internal, h, 1)
  DEBUG[73441][C-00000012]: pbx.c:4251 ast_pbx_h_exten_run: Spawn extension (from-internal,h,1) exited non-zero on 'PJSIP/1234-00000011'
  DEBUG[73441][C-00000012]: channel.c:2551 ast_hangup: Channel 0x7ff44c059230 'PJSIP/1234-00000011' hanging up.  Refs: 2
  DEBUG[73441][C-00000012]: chan_pjsip.c:2522 chan_pjsip_hangup:  PJSIP/1234-00000011
  DEBUG[73441][C-00000012]: chan_pjsip.c:2442 hangup_cause2sip: AST hangup cause 0 (no match found in PJSIP)
  DEBUG[73441][C-00000012]: chan_pjsip.c:2540 chan_pjsip_hangup:  Cause: 0
  DEBUG[49340]: chan_pjsip.c:2489 hangup:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip_session.c:3455 ast_sip_session_terminate:  PJSIP/1234-00000011 Response 0
  DEBUG[49340]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7ff44c022d10) DTLS srtp - stopped timeout timer'
  DEBUG[49340]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7ff44c022d10) DTLS srtp - stopped timeout timer'
  DEBUG[49340]: res_rtp_asterisk.c:2275 ast_rtp_dtls_stop: (0x7ff44c022d10) DTLS stop
  DEBUG[49340]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7ff44c022d10) DTLS srtp - stopped timeout timer'
  DEBUG[49340]: res_rtp_asterisk.c:2873 dtls_srtp_stop_timeout_timer: (0x7ff44c022d10) DTLS srtp - stopped timeout timer'
  DEBUG[49340]: res_rtp_asterisk.c:3982 rtp_deallocate_transport: (0x7ff44c022d10) ICE RTP transport deallocating
  DEBUG[49340]: rtp_engine.c:455 instance_destructor: Destroyed RTP instance '0x7ff44c022d10'
  DEBUG[49340]: res_pjsip_session.c:4485 handle_outgoing_request:  PJSIP/1234-00000011: Method is BYE
  DEBUG[49340]: res_pjsip_session.c:4495 handle_outgoing_request:  PJSIP/1234-00000011
  DEBUG[49340]: res_pjsip/pjsip_resolver.c:479 sip_resolve: Performing SIP DNS resolution of target 'W.X.Y.Z'
  DEBUG[49340]: res_pjsip/pjsip_resolver.c:506 sip_resolve: Transport type for target 'W.X.Y.Z' is 'UDP transport'
  DEBUG[49340]: res_pjsip/pjsip_resolver.c:527 sip_resolve: Target 'W.X.Y.Z' is an IP address, skipping resolution
  DEBUG[49340]: netsock2.c:170 ast_sockaddr_split_hostport: Splitting 'W.X.Y.Z' into...
  DEBUG[49340]: netsock2.c:224 ast_sockaddr_split_hostport: ...host 'W.X.Y.Z' and port ''.
  DEBUG[49340]: res_pjsip_session.c:4737 session_inv_on_tsx_state_changed:  PJSIP/1234-00000011 TSX State: Calling  Inv State: CONFIRMED
  DEBUG[49340]: res_pjsip_session.c:4357 __print_debug_details: Function session_inv_on_tsx_state_changed called on event TSX_STATE
  DEBUG[49340]: res_pjsip_session.c:4371 __print_debug_details: The state change pertains to the endpoint '1234(PJSIP/1234-00000011)'
  DEBUG[49340]: res_pjsip_session.c:4379 __print_debug_details: The inv session does NOT have an invite_tsx
  DEBUG[49340]: res_pjsip_session.c:4382 __print_debug_details: The UAC BYE transaction involved in this state change is 0x7ff474033968
  DEBUG[49340]: res_pjsip_session.c:4386 __print_debug_details: The current transaction state is Calling
  DEBUG[49340]: res_pjsip_session.c:4388 __print_debug_details: The transaction state change event is TX_MSG
  DEBUG[49340]: res_pjsip_session.c:4393 __print_debug_details: The current inv state is CONFIRMED
  DEBUG[49340]: res_pjsip_session.c:4925 session_inv_on_tsx_state_changed:  Nothing delayed
  DEBUG[49340]: res_pjsip_session.c:4169 session_on_tsx_state:  PJSIP/1234-00000011 TSX State: Calling  Inv State: CONFIRMED
  DEBUG[49340]: res_pjsip_session.c:4173 session_on_tsx_state:  Topology: Pending: (null topology)  Active: (null topology)
  DEBUG[49340]: res_pjsip_session.c:4178 session_on_tsx_state:
  DEBUG[49340]: res_pjsip_session.c:3527 ast_sip_session_terminate:
  DEBUG[49340]: channel.c:2198 ast_channel_destructor: Channel 0x7ff44c059230 'PJSIP/1234-00000011' destroying
  DEBUG[49340]: stasis.c:441 topic_dtor: Destroying topic. name: channel:1634298640.17, detail:
  DEBUG[49340]: stasis.c:450 topic_dtor: Topic 'channel:1634298640.17': 0x7ff44c0256c0 destroyed
  DEBUG[49340]: channel_internal_api.c:680 ast_channel_nativeformats_set:  <initializing>: MultistreamFormats: (nothing)
  DEBUG[49340]: channel_internal_api.c:692 ast_channel_nativeformats_set:  Channel is being initialized or destroyed
  DEBUG[49340]: chan_pjsip.c:2513 hangup:
  DEBUG[24363]: devicestate.c:361 _ast_device_state: No provider found, checking channel drivers for PJSIP - 1234
  DEBUG[24363]: devicestate.c:466 do_state_change: Changing state for PJSIP/1234 - state 1 (Not in use)
  DEBUG[24443]: app_queue.c:2586 device_state_cb: Device 'PJSIP/1234' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
  DEBUG[24370]: cdr.c:1460 cdr_object_finalize: Finalized CDR for PJSIP/1234-00000011 - start 1634298640.910665 answer 1634298640.911281 end 1634298642.414991 dur 1.504 bill 1.503 dispo ANSWERED
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:502 distributor: Searching for serializer associated with dialog dlg0x7ff47400f4c8 for Response msg 200/BYE/cseq=30858 (rdata0x7ff468002928)
  DEBUG[24381]: res_pjsip/pjsip_distributor.c:510 distributor: Found serializer pjsip/distributor-00000034 associated with dialog dlg0x7ff47400f4c8
  DEBUG[49340]: res_pjsip_session.c:4192 session_on_rx_response:  1234 Method: BYE Status: 200
  DEBUG[49340]: res_pjsip_session.c:4195 session_on_rx_response:
  DEBUG[49340]: res_pjsip_session.c:4619 session_inv_on_state_changed:  1234 Event: TSX_STATE  Inv State: DISCONNCTD
  DEBUG[49340]: res_pjsip_session.c:4357 __print_debug_details: Function session_inv_on_state_changed called on event TSX_STATE
  DEBUG[49340]: res_pjsip_session.c:4371 __print_debug_details: The state change pertains to the endpoint '1234()'
  DEBUG[49340]: res_pjsip_session.c:4379 __print_debug_details: The inv session does NOT have an invite_tsx
  DEBUG[49340]: res_pjsip_session.c:4391 __print_debug_details: There is no transaction involved in this state change
  DEBUG[49340]: res_pjsip_session.c:4393 __print_debug_details: The current inv state is DISCONNCTD
  DEBUG[49340]: res_pjsip_session.c:4645 session_inv_on_state_changed: 1234: Source of transaction state change is RX_MSG
  DEBUG[49340]: res_pjsip_session.c:4587 handle_incoming_before_media: 1234: Received response
  DEBUG[49340]: res_pjsip_session.c:4454 handle_incoming_response:  1234: Response is 200 OK
  DEBUG[49340]: res_pjsip_session.c:4466 handle_incoming_response:  1234
  DEBUG[49340]: res_pjsip_session.c:4693 session_inv_on_state_changed:
  DEBUG[49340]: res_pjsip_session.c:4737 session_inv_on_tsx_state_changed:  1234 TSX State: Completed  Inv State: DISCONNCTD
  DEBUG[49340]: res_pjsip_session.c:4357 __print_debug_details: Function session_inv_on_tsx_state_changed called on event TSX_STATE
  DEBUG[49340]: res_pjsip_session.c:4371 __print_debug_details: The state change pertains to the endpoint '1234()'
  DEBUG[49340]: res_pjsip_session.c:4379 __print_debug_details: The inv session does NOT have an invite_tsx
  DEBUG[49340]: res_pjsip_session.c:4382 __print_debug_details: The UAC BYE transaction involved in this state change is 0x7ff474033968
  DEBUG[49340]: res_pjsip_session.c:4386 __print_debug_details: The current transaction state is Completed
  DEBUG[49340]: res_pjsip_session.c:4388 __print_debug_details: The transaction state change event is RX_MSG
  DEBUG[49340]: res_pjsip_session.c:4393 __print_debug_details: The current inv state is DISCONNCTD
  DEBUG[49340]: res_pjsip_session.c:4454 handle_incoming_response:  1234: Response is 200 OK
  DEBUG[49340]: res_pjsip_session.c:4466 handle_incoming_response:  1234
  DEBUG[49340]: res_pjsip_session.c:4885 session_inv_on_tsx_state_changed: 1234: BYE received final response code 200
  DEBUG[49340]: res_pjsip_session.c:4925 session_inv_on_tsx_state_changed:  Nothing delayed
  DEBUG[49340]: res_pjsip_session.c:4169 session_on_tsx_state:  1234 TSX State: Completed  Inv State: DISCONNCTD
  DEBUG[49340]: res_pjsip_session.c:4173 session_on_tsx_state:  Topology: Pending: (null topology)  Active: (null topology)
  DEBUG[49340]: res_pjsip_session.c:4178 session_on_tsx_state:
  DEBUG[49340]: chan_pjsip.c:2975 chan_pjsip_session_end:  1234
  DEBUG[49340]: chan_pjsip.c:2978 chan_pjsip_session_end:  No channel
  DEBUG[24381]: res_pjsip_session.c:4737 session_inv_on_tsx_state_changed:  1234 TSX State: Terminated  Inv State: DISCONNCTD
  DEBUG[24381]: res_pjsip_session.c:4357 __print_debug_details: Function session_inv_on_tsx_state_changed called on event TSX_STATE
  DEBUG[24381]: res_pjsip_session.c:4371 __print_debug_details: The state change pertains to the endpoint '1234()'
  DEBUG[24381]: res_pjsip_session.c:4379 __print_debug_details: The inv session does NOT have an invite_tsx
  DEBUG[24381]: res_pjsip_session.c:4382 __print_debug_details: The UAC BYE transaction involved in this state change is 0x7ff474033968
  DEBUG[24381]: res_pjsip_session.c:4386 __print_debug_details: The current transaction state is Terminated
  DEBUG[24381]: res_pjsip_session.c:4388 __print_debug_details: The transaction state change event is TIMER
  DEBUG[24381]: res_pjsip_session.c:4393 __print_debug_details: The current inv state is DISCONNCTD
  DEBUG[24381]: res_pjsip_session.c:4913 session_inv_on_tsx_state_changed:  Disconnected
  DEBUG[24381]: res_pjsip_session.c:4169 session_on_tsx_state:  (null session) TSX State: Terminated  Inv State: DISCONNCTD
  DEBUG[24381]: res_pjsip_session.c:4178 session_on_tsx_state:
  DEBUG[49340]: res_pjsip_session.c:2911 session_destructor: 1234: Destroying SIP session

jcolp · October 15, 2021, 12:31pm

Asterisk was not built with the “Macro” dialplan application enabled in menuselect. This is required for FreePBX.

lmon · October 15, 2021, 2:28pm

I checked in menu Select and can’t find anything on Dialplan “Macro/option” to enable .
I found this, where I have already enabled anything ( by default )

In application, everything is chcked anyway as well in core and Extended

jcolp · October 15, 2021, 2:29pm

The app_macro module is at the bottom of the applications list under Deprecated.

lmon · October 15, 2021, 2:32pm

Thanks a lot Jcolp, found ! I was not looking in to the depreacted ones …
Rebuilding !

lmon · October 15, 2021, 2:38pm

and working ! Thanks a lot !

system · October 22, 2021, 2:38pm

This topic was automatically closed 7 days after the last reply. New replies are no longer allowed.