[May 18 07:38:48] DEBUG[19102] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg INVITE/cseq=20 (rdata0x7f5b54001868) [May 18 07:38:48] DEBUG[19102] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000051 to use for Request msg INVITE/cseq=20 (rdata0x7f5b54001868) [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '4.4.7.7' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '4.4.7.7' and port ''. [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]-[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]-[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]-[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username 'sip_client' domain 'example.com' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_user.c: Identified by From username 'sip_client' domain 'example.com' [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: (null session) Request: INVITE [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Request: [May 18 07:38:48] DEBUG[20189] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000051 to use for Request msg INVITE/cseq=20 (rdata0x7f5b54037d28) [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: sip_client [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: Direct media no glare mitigation [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Call (TCP:4.4.7.7:2762) to extension '600' sending 100 Trying [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Method is INVITE, Response is 100 Trying [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client Event: TSX_STATE Inv State: INCOMING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client()' [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f5b80106ba8) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: There is no transaction involved in this state change [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current inv state is INCOMING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Source of transaction state change is TX_MSG [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client TSX State: Proceeding Inv State: INCOMING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client()' [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f5b80106ba8) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f5b80106ba8 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current transaction state is Proceeding [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The transaction state change event is TX_MSG [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current inv state is INCOMING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Nothing delayed [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client TSX State: Proceeding Inv State: INCOMING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Topology: Pending: (null topology) Active: (null topology) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Media count: 1 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Processing stream 0 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Using audio-0 for new stream name [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Using new stream 0:audio-0:audio:sendrecv (nothing) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client Adding position 0 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Creating new media session [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Setting media session as default for audio [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Done [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Negotiating incoming SDP media stream 0:audio-0:audio:sendrecv (nothing) using audio SDP handler [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: sip_client [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: Incompatible transport [May 18 07:38:48] ERROR[20189] res_pjsip_session.c: sip_client: Couldn't negotiate stream 0:audio-0:audio:sendrecv (nothing) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Couldn't negotiate stream 0:audio-0:audio:sendrecv (nothing) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Handled? no [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Method is INVITE, Response is 488 Not Acceptable Here [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client Event: TSX_STATE Inv State: DISCONNCTD [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client()' [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f5b80106ba8) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: There is no transaction involved in this state change [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current inv state is DISCONNCTD [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Source of transaction state change is TX_MSG [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client TSX State: Completed Inv State: DISCONNCTD [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client()' [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f5b80106ba8) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f5b80106ba8 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current transaction state is Completed [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The transaction state change event is TX_MSG [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current inv state is DISCONNCTD [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Disconnected [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: (null session) TSX State: Completed Inv State: DISCONNCTD [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Request: Session: sip_client [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: (null session) Handled request INVITE ? yes [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: sip_client [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: No channel [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Destroying SIP session [May 18 07:38:48] DEBUG[19102] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f5b800fc3c8 for Request msg ACK/cseq=20 (rdata0x7f5b54001868) [May 18 07:38:48] DEBUG[19102] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000051 to use for Request msg ACK/cseq=20 (rdata0x7f5b54001868) [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '4.4.7.7' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '4.4.7.7' and port ''. [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]-[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]-[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]-[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username 'sip_client' domain 'example.com' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_user.c: Identified by From username 'sip_client' domain 'example.com' [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: (null session) TSX State: Confirmed Inv State: DISCONNCTD [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: inv_session 0x7f5b480dc608 has no ast session [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f5b80106ba8) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f5b80106ba8 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current transaction state is Confirmed [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The transaction state change event is RX_MSG [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current inv state is DISCONNCTD [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Session ended [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: (null session) TSX State: Confirmed Inv State: DISCONNCTD [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:48] DEBUG[19102] res_pjsip_session.c: (null session) TSX State: Terminated Inv State: DISCONNCTD [May 18 07:38:48] DEBUG[19102] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [May 18 07:38:48] DEBUG[19102] res_pjsip_session.c: inv_session 0x7f5b480dc608 has no ast session [May 18 07:38:48] DEBUG[19102] res_pjsip_session.c: The inv session does NOT have an invite_tsx [May 18 07:38:48] DEBUG[19102] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f5b80106ba8 [May 18 07:38:48] DEBUG[19102] res_pjsip_session.c: The current transaction state is Terminated [May 18 07:38:48] DEBUG[19102] res_pjsip_session.c: The transaction state change event is TIMER [May 18 07:38:48] DEBUG[19102] res_pjsip_session.c: The current inv state is DISCONNCTD [May 18 07:38:48] DEBUG[19102] res_pjsip_session.c: Session ended [May 18 07:38:48] DEBUG[19102] res_pjsip_session.c: (null session) TSX State: Terminated Inv State: DISCONNCTD [May 18 07:38:48] DEBUG[19102] res_pjsip_session.c: [May 18 07:38:48] DEBUG[19102] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg INVITE/cseq=20 (rdata0x7f5b54001868) [May 18 07:38:48] DEBUG[19102] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000045 to use for Request msg INVITE/cseq=20 (rdata0x7f5b54001868) [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '4.4.7.7' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '4.4.7.7' and port ''. [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]-[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]-[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]-[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_ip.c: Source address 4.4.7.7:2762 does not match identify '[redacted]' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_user.c: Attempting identify by From username 'sip_client' domain 'example.com' [May 18 07:38:48] DEBUG[20189] res_pjsip_endpoint_identifier_user.c: Identified by From username 'sip_client' domain 'example.com' [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: (null session) Request: INVITE [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Request: [May 18 07:38:48] DEBUG[20189] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-00000045 to use for Request msg INVITE/cseq=20 (rdata0x7f5b54037d28) [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: sip_client [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: Direct media no glare mitigation [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Call (TCP:4.4.7.7:2762) to extension '600' sending 100 Trying [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Method is INVITE, Response is 100 Trying [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client Event: TSX_STATE Inv State: INCOMING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client()' [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f5b800fc3c8) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: There is no transaction involved in this state change [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current inv state is INCOMING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Source of transaction state change is TX_MSG [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client TSX State: Proceeding Inv State: INCOMING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client()' [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f5b800fc3c8) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f5b800fc3c8 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current transaction state is Proceeding [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The transaction state change event is TX_MSG [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current inv state is INCOMING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Nothing delayed [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client TSX State: Proceeding Inv State: INCOMING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Topology: Pending: (null topology) Active: (null topology) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Media count: 1 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Processing stream 0 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Using audio-0 for new stream name [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Using new stream 0:audio-0:audio:sendrecv (nothing) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client Adding position 0 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Creating new media session [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Setting media session as default for audio [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Done [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Negotiating incoming SDP media stream 0:audio-0:audio:sendrecv (nothing) using audio SDP handler [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: sip_client [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '5.4.2.6' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '5.4.2.6' and port ''. [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f5b481044c0' [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) RTP allocated port 12072 [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE creating session [::]:12072 (12072) [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE create [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add system candidates [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '10.75.22.247' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '10.75.22.247' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: 10.75.22.247:12072, 2130706431 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '10.75.22.5' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '10.75.22.5' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: 10.75.22.5:12072, 2130706431 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '10.75.22.8' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '10.75.22.8' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: 10.75.22.8:12072, 2130706431 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '10.75.22.9' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '10.75.22.9' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: 10.75.22.9:12072, 2130706431 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '2001:123:ab:123::2' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '2001:123:ab:123::2' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: [2001:123:ab:123::2]:12072, 2130706431 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting 'fd31:aeb1:48df::2' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host 'fd31:aeb1:48df::2' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: [fd31:aeb1:48df::2]:12072, 2130706431 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting 'fe80::feaa:14ff:fe6c:4fd6' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host 'fe80::feaa:14ff:fe6c:4fd6' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: [fe80::feaa:14ff:fe6c:4fd6]:12072, 2130706431 [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE request STUN TCP RTP candidate [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '7.3.7.1' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '7.3.7.1' and port ''. [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '10.75.22.247' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '10.75.22.247' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: 7.3.7.1:12072, 1694498815 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: RTP instance '0x7f5b481044c0' is setup and ready to go [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting 'server.example.com' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host 'server.example.com' and port ''. [May 18 07:38:48] DEBUG[20189] acl.c: Multiple addresses. Using the first only [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add system candidates [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '10.75.22.247' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '10.75.22.247' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: 10.75.22.247:12073, 2130706430 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '10.75.22.5' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '10.75.22.5' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: 10.75.22.5:12073, 2130706430 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '10.75.22.8' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '10.75.22.8' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: 10.75.22.8:12073, 2130706430 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '10.75.22.9' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '10.75.22.9' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: 10.75.22.9:12073, 2130706430 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '2001:123:ab:123::2' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '2001:123:ab:123::2' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: [2001:123:ab:123::2]:12073, 2130706430 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting 'fd31:aeb1:48df::2' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host 'fd31:aeb1:48df::2' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: [fd31:aeb1:48df::2]:12073, 2130706430 [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting 'fe80::feaa:14ff:fe6c:4fd6' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host 'fe80::feaa:14ff:fe6c:4fd6' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: [fe80::feaa:14ff:fe6c:4fd6]:12073, 2130706430 [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE request STUN UDP RTCP candidate [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '7.3.7.1' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '7.3.7.1' and port ''. [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '10.75.22.247' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '10.75.22.247' and port ''. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE add candidate: 7.3.7.1:12073, 1694498814 [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP setup on RTP instance [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: sip_client [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: sip_client [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 3 based on m type on 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 9 based on m type on 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 10 based on m type on 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 11 based on m type on 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: [May 18 07:38:48] DEBUG[20189] res_pjsip_session/pjsip_session_caps.c: 'sip_client' Caps for incoming audio call with pref 'local' - remote: (ulaw|gsm|alaw|g722|slin|opus|speex16|speex|ilbc|speex32) local: (opus|codec2|g723|ulaw|alaw|gsm|g726|g726aal2|adpcm|slin|slin12|slin16|slin24|slin32|slin44|slin48|slin96|slin192|lpc10|g729|speex|speex16|speex32|ilbc|g722|siren7|siren14|testlaw|g719|jpeg|png|h261|h263|h263p|h264|h265|mpeg4|vp8|vp9|red|t140|t38|silk8|silk12|silk16|silk24) joint: (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722) [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Crossover copying tx to rx payload mapping 0 (0x3235bf8) from 0x7f5b1bc043f0 to 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Crossover copying tx to rx payload mapping 3 (0x3238ba8) from 0x7f5b1bc043f0 to 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Crossover copying tx to rx payload mapping 8 (0x32359e8) from 0x7f5b1bc043f0 to 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Crossover copying tx to rx payload mapping 9 (0x3235a38) from 0x7f5b1bc043f0 to 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Crossover copying tx to rx payload mapping 10 (0x3235a88) from 0x7f5b1bc043f0 to 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Crossover copying tx to rx payload mapping 96 (0x7f5b481025a8) from 0x7f5b1bc043f0 to 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Crossover copying tx to rx payload mapping 97 (0x7f5b48102708) from 0x7f5b1bc043f0 to 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Crossover copying tx to rx payload mapping 98 (0x7f5b4816da08) from 0x7f5b1bc043f0 to 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Crossover copying tx to rx payload mapping 99 (0x7f5b4816db18) from 0x7f5b1bc043f0 to 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Crossover copying tx to rx payload mapping 102 (0x7f5b480ed608) from 0x7f5b1bc043f0 to 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Crossover copying tx to rx payload mapping 104 (0x7f5b4816da58) from 0x7f5b1bc043f0 to 0x7f5b1bc043f0 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying rx payload mapping 0 (0x3235bf8) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying rx payload mapping 3 (0x3238ba8) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying rx payload mapping 8 (0x32359e8) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying rx payload mapping 9 (0x3235a38) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying rx payload mapping 10 (0x3235a88) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying rx payload mapping 96 (0x7f5b481025a8) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying rx payload mapping 97 (0x7f5b48102708) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying rx payload mapping 98 (0x7f5b4816da08) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying rx payload mapping 99 (0x7f5b4816db18) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying rx payload mapping 102 (0x7f5b480ed608) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying rx payload mapping 104 (0x7f5b4816da58) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 0 (0x3235bf8) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 3 (0x3238ba8) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 8 (0x32359e8) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 9 (0x3235a38) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 10 (0x3235a88) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 96 (0x7f5b481025a8) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 97 (0x7f5b48102708) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 98 (0x7f5b4816da08) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 99 (0x7f5b4816db18) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 102 (0x7f5b480ed608) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 104 (0x7f5b4816da58) from 0x7f5b1bc043f0 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Media stream 0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722) handled by audio [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Done with stream 0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Handled? yes [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Processing streams [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Processing stream 0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client Adding position 0 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Using existing media_session [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client Stream: 0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722) [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: sip_client Type: audio 0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722) [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP ignoring duplicate property [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE stopped [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: RC: 1 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Had handler [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Stream 0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722) added [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Done with 0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Adding bundle groups (if available) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Copying connection details [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Processing media 0 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Media 0 reset [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: sip_client: Method is INVITE [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: sip_client [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: sip_client [May 18 07:38:48] DEBUG[20189] channel_internal_api.c: : Formats: (none) [May 18 07:38:48] DEBUG[20189] channel_internal_api.c: Channel is being initialized or destroyed [May 18 07:38:48] DEBUG[20189] stasis.c: Creating topic. name: channel:pbx.example.com-1621337928.2, detail: [May 18 07:38:48] DEBUG[20189] stasis.c: Topic 'channel:pbx.example.com-1621337928.2': 0x7f5b481037a0 created [May 18 07:38:48] DEBUG[20189] channel.c: Channel 0x7f5b48173f00 'PJSIP/sip_client-00000001' allocated [May 18 07:38:48] DEBUG[19070] threadpool.c: Increasing threadpool stasis/pool's size by 1 [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: Topology: <0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722)> Formats: (opus|codec2|g723|ulaw|alaw|gsm|g726|g726aal2|adpcm|slin|slin12|slin16|slin24|slin32|slin44|slin48|slin96|slin192|lpc10|g729|speex|speex16|speex32|ilbc|g722|siren7|siren14|testlaw|g719|jpeg|png|h261|h263|h263p|h264|h265|mpeg4|vp8|vp9|red|t140|t38|silk8|silk12|silk16|silk24) [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: Compatible? yes [May 18 07:38:48] DEBUG[20189] channel_internal_api.c: PJSIP/sip_client-00000001: MultistreamFormats: (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722) [May 18 07:38:48] DEBUG[20189] channel_internal_api.c: Set native formats but not topology [May 18 07:38:48] DEBUG[20189] channel_internal_api.c: PJSIP/sip_client-00000001: <0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722)> [May 18 07:38:48] DEBUG[20189] channel_internal_api.c: Used provided topology [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: Started PBX on new PJSIP channel PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: RC: 0 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Request: Session: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: (null session) Handled request INVITE ? yes [May 18 07:38:48] DEBUG[20202][C-00000002] pbx.c: Launching 'Set' [May 18 07:38:48] DEBUG[20202][C-00000002] pbx.c: Launching 'BackGround' [May 18 07:38:48] DEBUG[20202][C-00000002] chan_pjsip.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[19082] devicestate.c: No provider found, checking channel drivers for PJSIP - sip_client [May 18 07:38:48] DEBUG[19082] devicestate.c: Changing state for PJSIP/sip_client - state 2 (In use) [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001: Applying negotiated SDP media stream 'audio' using audio SDP handler [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: PJSIP/sip_client-00000001 Stream: 0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722) [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP ignoring duplicate property [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '5.4.2.6' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '5.4.2.6' and port ''. [May 18 07:38:48] DEBUG[20189] acl.c: For destination '5.4.2.6', our source address is '10.75.22.247'. [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP setting address on RTP instance [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: (0x7f5b481044c0) ICE process attributes [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE set role failed; no ice instance [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: PJSIP/sip_client-00000001 ANSWER [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 0 based on m type on 0x7f5b1bc04090 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f5b1bc04090 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 3 based on m type on 0x7f5b1bc04090 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 9 based on m type on 0x7f5b1bc04090 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 10 based on m type on 0x7f5b1bc04090 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Setting tx payload type 11 based on m type on 0x7f5b1bc04090 [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 0 (0x3235bf8) from 0x7f5b1bc04090 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 3 (0x3238ba8) from 0x7f5b1bc04090 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 8 (0x32359e8) from 0x7f5b1bc04090 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 9 (0x3235a38) from 0x7f5b1bc04090 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 10 (0x3235a88) from 0x7f5b1bc04090 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 96 (0x7f5b481759c8) from 0x7f5b1bc04090 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 97 (0x7f5b4810b328) from 0x7f5b1bc04090 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 98 (0x7f5b48175b28) from 0x7f5b1bc04090 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 99 (0x7f5b4810b378) from 0x7f5b1bc04090 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 102 (0x7f5b481758e8) from 0x7f5b1bc04090 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] rtp_engine.c: Copying tx payload mapping 104 (0x7f5b48175b78) from 0x7f5b1bc04090 to 0x7f5b48104698 [May 18 07:38:48] DEBUG[20189] channel_internal_api.c: PJSIP/sip_client-00000001: MultistreamFormats: (opus) [May 18 07:38:48] DEBUG[20189] channel_internal_api.c: Set native formats but not topology [May 18 07:38:48] DEBUG[20189] channel.c: Channel PJSIP/sip_client-00000001 setting read format path: opus -> opus [May 18 07:38:48] DEBUG[20189] channel.c: Channel PJSIP/sip_client-00000001 setting write format path: opus -> opus [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) DTLS - ast_rtp_activate rtp=0x7f5b48106580 - setup and perform DTLS' [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b48106580) DTLS perform handshake - ssl = (nil), setup = 0 [May 18 07:38:48] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b48106580) DTLS perform handshake - ssl = (nil), setup = 0 [May 18 07:38:48] DEBUG[20189] res_pjsip_sdp_rtp.c: Handled [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001: Applied negotiated SDP media stream 'audio' using audio SDP handler [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001: Applied negotiated SDP media stream 'audio' using audio SDP handler [May 18 07:38:48] DEBUG[20189] channel_internal_api.c: PJSIP/sip_client-00000001: <0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722)> [May 18 07:38:48] DEBUG[20189] channel_internal_api.c: Used provided topology [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001: Method is INVITE, Response is 200 OK [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[20189] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to 10.75.22.8:5060 (this may be re-written again later) [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '4.4.7.7' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '4.4.7.7' and port ''. [May 18 07:38:48] DEBUG[20189] netsock2.c: Splitting '10.75.22.8' into... [May 18 07:38:48] DEBUG[20189] netsock2.c: ...host '10.75.22.8' and port ''. [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: (null session): Setting external media address to 7.3.7.1 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 Event: TSX_STATE Inv State: CONNECTING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client(PJSIP/sip_client-00000001)' [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f5b800fc3c8) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: There is no transaction involved in this state change [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current inv state is CONNECTING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001: Source of transaction state change is TX_MSG [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 TSX State: Completed Inv State: CONNECTING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client(PJSIP/sip_client-00000001)' [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f5b800fc3c8) [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f5b800fc3c8 [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current transaction state is Completed [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The transaction state change event is TX_MSG [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: The current inv state is CONNECTING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Nothing delayed [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 TSX State: Completed Inv State: CONNECTING [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722)> [May 18 07:38:48] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:48] DEBUG[20189] chan_pjsip.c: [May 18 07:38:48] DEBUG[20202][C-00000002] chan_pjsip.c: [May 18 07:38:48] DEBUG[20202][C-00000002] chan_pjsip.c: PJSIP/sip_client-00000001: Indicated Stop generators [May 18 07:38:48] DEBUG[20202][C-00000002] chan_pjsip.c: PJSIP/sip_client-00000001 [May 18 07:38:48] DEBUG[19211] app_queue.c: Device 'PJSIP/sip_client' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 18 07:38:48] DEBUG[19102] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to 10.75.22.8:5060 (this may be re-written again later) [May 18 07:38:48] DEBUG[19102] netsock2.c: Splitting '4.4.7.7' into... [May 18 07:38:48] DEBUG[19102] netsock2.c: ...host '4.4.7.7' and port ''. [May 18 07:38:48] DEBUG[20202][C-00000002] channel.c: Didn't receive a media frame from PJSIP/sip_client-00000001 within 500 ms of answering. Continuing anyway [May 18 07:38:48] DEBUG[20202][C-00000002] channel.c: Channel PJSIP/sip_client-00000001 setting write format path: gsm -> opus [May 18 07:38:48] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP ooh, format changed from none to opus [May 18 07:38:48] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP starting transmission [May 18 07:38:48] DEBUG[20202][C-00000002] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP 0x7f5b48106580 -- Received packet from 4.4.7.7:2814, dropping due to strict RTP protection. Qualifying new stream. [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP 0x7f5b48106580 -- Received packet from 4.4.7.7:2814, dropping due to strict RTP protection. Will switch to it in 3 packets. [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP 0x7f5b48106580 -- Received packet from 4.4.7.7:2814, dropping due to strict RTP protection. Will switch to it in 2 packets. [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP 0x7f5b48106580 -- Received packet from 4.4.7.7:2814, dropping due to strict RTP protection. Will switch to it in 1 packets. [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP 0x7f5b48106580 -- Received packet from 4.4.7.7:2814, dropping due to strict RTP protection. Will switch to it in 3 packets. [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP 0x7f5b48106580 -- Received packet from 4.4.7.7:2814, dropping due to strict RTP protection. Will switch to it in 2 packets. [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP 0x7f5b48106580 -- Received packet from 4.4.7.7:2814, dropping due to strict RTP protection. Will switch to it in 1 packets. [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP 0x7f5b48106580 -- Received packet from 4.4.7.7:2814, dropping due to strict RTP protection. Will switch to it in 3 packets. [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP 0x7f5b48106580 -- Received packet from 4.4.7.7:2814, dropping due to strict RTP protection. Will switch to it in 2 packets. [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP 0x7f5b48106580 -- Received packet from 4.4.7.7:2814, dropping due to strict RTP protection. Will switch to it in 1 packets. [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2814 [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:49] DEBUG[19102] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f5b80106ba8 for Request msg ACK/cseq=20 (rdata0x7f5b54001868) [May 18 07:38:49] DEBUG[19102] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000045 associated with dialog dlg0x7f5b80106ba8 [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 TSX State: Terminated Inv State: CONNECTING [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client(PJSIP/sip_client-00000001)' [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: The inv session does NOT have an invite_tsx [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: The UAS INVITE transaction involved in this state change is 0x7f5b800fc3c8 [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: The current transaction state is Terminated [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: The transaction state change event is USER [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: The current inv state is CONNECTING [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: Nothing delayed [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 TSX State: Terminated Inv State: CONNECTING [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722)> [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 Event: RX_MSG Inv State: CONFIRMED [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_state_changed called on event RX_MSG [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client(PJSIP/sip_client-00000001)' [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: The inv session does NOT have an invite_tsx [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: There is no transaction involved in this state change [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: The current inv state is CONFIRMED [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001: Received request [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001: Method is ACK [May 18 07:38:49] DEBUG[20189] chan_pjsip.c: PJSIP/sip_client-00000001 [May 18 07:38:49] DEBUG[20189] chan_pjsip.c: PJSIP/sip_client-00000001: Queueing SRCCHANGE [May 18 07:38:49] DEBUG[20189] chan_pjsip.c: PJSIP/sip_client-00000001 [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 Request: ACK [May 18 07:38:49] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 Handled request ACK ? yes [May 18 07:38:49] DEBUG[19102] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f5b80106ba8 for Request msg ACK/cseq=20 (rdata0x7f5b54001868) [May 18 07:38:49] DEBUG[19102] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000045 associated with dialog dlg0x7f5b80106ba8 [May 18 07:38:49] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:50] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:50] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP got report of 156 bytes from 4.4.7.7:2800 [May 18 07:38:50] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:51] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:51] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:51] DEBUG[19113] res_pjsip_registrar.c: Woke up at 1621337931 Interval: 30 [May 18 07:38:51] DEBUG[19113] res_pjsip_registrar.c: Expiring 0 contacts [May 18 07:38:52] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:52] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:53] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP got report of 156 bytes from 4.4.7.7:2800 [May 18 07:38:53] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:53] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:54] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:54] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:55] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:55] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP got report of 156 bytes from 4.4.7.7:2800 [May 18 07:38:55] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:56] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:56] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:57] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:57] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:58] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP got report of 156 bytes from 4.4.7.7:2800 [May 18 07:38:58] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:58] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:59] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:38:59] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:00] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:00] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:01] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP got report of 156 bytes from 4.4.7.7:2800 [May 18 07:39:01] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:01] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:02] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:02] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:03] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:03] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:04] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:04] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:05] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:05] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:06] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP got report of 156 bytes from 4.4.7.7:2800 [May 18 07:39:06] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:06] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:07] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:07] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:08] DEBUG[20201] threadpool.c: Worker thread idle timeout reached. Dying. [May 18 07:39:08] DEBUG[19070] threadpool.c: Destroying worker thread 52 [May 18 07:39:08] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:08] DEBUG[20202][C-00000002] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 18 07:39:08] DEBUG[20202][C-00000002] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 18 07:39:08] DEBUG[20202][C-00000002] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 18 07:39:08] DEBUG[20202][C-00000002] channel.c: Channel PJSIP/sip_client-00000001 setting write format path: opus -> opus [May 18 07:39:08] DEBUG[20202][C-00000002] pbx.c: Launching 'NoOp' [May 18 07:39:08] DEBUG[19070] threadpool.c: Increasing threadpool stasis/pool's size by 1 [May 18 07:39:08] DEBUG[20202][C-00000002] pbx.c: Launching 'Goto' [May 18 07:39:08] DEBUG[20202][C-00000002] pbx.c: Launching 'Echo' [May 18 07:39:08] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 720, ms is 35 [May 18 07:39:08] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 4 [May 18 07:39:08] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 672, ms is 34 [May 18 07:39:08] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:09] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:09] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 4 [May 18 07:39:09] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 864, ms is 2 [May 18 07:39:09] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:09] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 912, ms is 39 [May 18 07:39:09] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 720, ms is 35 [May 18 07:39:09] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 4 [May 18 07:39:09] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 672, ms is 34 [May 18 07:39:09] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:09] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 4 [May 18 07:39:10] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 4 [May 18 07:39:10] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 720, ms is 5 [May 18 07:39:10] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 816, ms is 37 [May 18 07:39:10] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:10] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:10] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 672, ms is 34 [May 18 07:39:10] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:10] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:10] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:11] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 36 [May 18 07:39:11] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:11] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:11] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:11] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 864, ms is 38 [May 18 07:39:11] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:11] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP got report of 156 bytes from 4.4.7.7:2800 [May 18 07:39:11] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:11] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 816, ms is 37 [May 18 07:39:12] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:12] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:12] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:12] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 816, ms is 37 [May 18 07:39:12] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:13] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 816, ms is 37 [May 18 07:39:13] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:13] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:13] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:14] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 36 [May 18 07:39:14] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:14] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 1008, ms is 41 [May 18 07:39:14] DEBUG[19102] res_pjsip.c: 0x7f5b4c002c10: PJSIP tsx timer expired [May 18 07:39:14] DEBUG[19102] res_pjsip.c: 0x7f5b4c002c10: Callbacks executed [May 18 07:39:14] DEBUG[19102] res_pjsip.c: 0x7f5b4c002c10: wrapper destroyed [May 18 07:39:14] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 864, ms is 38 [May 18 07:39:14] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:14] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 912, ms is 1 [May 18 07:39:14] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 672, ms is 6 [May 18 07:39:15] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:15] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 720, ms is 5 [May 18 07:39:15] DEBUG[19118] res_xmpp.c: JABBER: Sending Keep-Alive Ping for client 'themurrells' [May 18 07:39:15] DEBUG[19118] res_xmpp.c: XML parsing successful [May 18 07:39:15] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:15] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 864, ms is 2 [May 18 07:39:15] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:15] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 864, ms is 38 [May 18 07:39:15] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 912, ms is 1 [May 18 07:39:15] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 720, ms is 5 [May 18 07:39:16] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:16] DEBUG[19119] res_xmpp.c: JABBER: Sending Keep-Alive Ping for client 'carole' [May 18 07:39:16] DEBUG[19119] res_xmpp.c: XML parsing successful [May 18 07:39:16] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:16] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:16] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 672, ms is 34 [May 18 07:39:16] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 4 [May 18 07:39:16] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 1056, ms is 42 [May 18 07:39:16] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:17] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:17] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 1008, ms is 41 [May 18 07:39:17] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:17] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 720, ms is 5 [May 18 07:39:17] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 672, ms is 34 [May 18 07:39:17] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 4 [May 18 07:39:17] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTCP got report of 156 bytes from 4.4.7.7:2800 [May 18 07:39:17] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 1056, ms is 42 [May 18 07:39:17] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:17] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 4 [May 18 07:39:17] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 36 [May 18 07:39:18] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:18] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:18] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:18] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 864, ms is 38 [May 18 07:39:18] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 912, ms is 1 [May 18 07:39:18] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 768, ms is 36 [May 18 07:39:18] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 40 [May 18 07:39:18] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 816, ms is 37 [May 18 07:39:18] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 864, ms is 2 [May 18 07:39:18] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) RTP audio difference is 960, ms is 0 [May 18 07:39:19] DEBUG[20202][C-00000002] res_rtp_asterisk.c: (0x7f5b481044c0) STUN using IPv6 mapped address 4.4.7.7:2800 [May 18 07:39:19] DEBUG[19102] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f5b80106ba8 for Request msg BYE/cseq=21 (rdata0x7f5b54001868) [May 18 07:39:19] DEBUG[19102] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000045 associated with dialog dlg0x7f5b80106ba8 [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 TSX State: Completed Inv State: CONFIRMED [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client(PJSIP/sip_client-00000001)' [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The inv session does NOT have an invite_tsx [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f5b800fc3c8 [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The current transaction state is Completed [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The transaction state change event is TX_MSG [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The current inv state is CONFIRMED [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: Nothing delayed [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 TSX State: Completed Inv State: CONFIRMED [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722)> [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 Event: TSX_STATE Inv State: DISCONNCTD [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client(PJSIP/sip_client-00000001)' [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The inv session does NOT have an invite_tsx [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: There is no transaction involved in this state change [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The current inv state is DISCONNCTD [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001: Source of transaction state change is RX_MSG [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001: Received request [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001: Method is BYE [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 TSX State: Completed Inv State: DISCONNCTD [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client(PJSIP/sip_client-00000001)' [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The inv session does NOT have an invite_tsx [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f5b800fc3c8 [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The current transaction state is Completed [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The transaction state change event is RX_MSG [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: The current inv state is DISCONNCTD [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: Nothing delayed [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 TSX State: Completed Inv State: DISCONNCTD [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (opus|ulaw|alaw|gsm|slin|speex|speex16|speex32|ilbc|g722)> [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: [May 18 07:39:19] DEBUG[20189] chan_pjsip.c: PJSIP/sip_client-00000001 [May 18 07:39:19] DEBUG[20189] chan_pjsip.c: [May 18 07:39:19] DEBUG[20202][C-00000002] pbx.c: Spawn extension (internal-sip,1,1) exited non-zero on 'PJSIP/sip_client-00000001' [May 18 07:39:19] DEBUG[20202][C-00000002] channel.c: Soft-Hanging (0x10) up channel 'PJSIP/sip_client-00000001' [May 18 07:39:19] DEBUG[20202][C-00000002] channel.c: Channel 0x7f5b48173f00 'PJSIP/sip_client-00000001' hanging up. Refs: 2 [May 18 07:39:19] DEBUG[20202][C-00000002] chan_pjsip.c: PJSIP/sip_client-00000001 [May 18 07:39:19] DEBUG[20202][C-00000002] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [May 18 07:39:19] DEBUG[20202][C-00000002] chan_pjsip.c: Cause: 0 [May 18 07:39:19] DEBUG[20189] chan_pjsip.c: PJSIP/sip_client-00000001 [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: PJSIP/sip_client-00000001 Response 0 [May 18 07:39:19] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) DTLS srtp - stopped timeout timer' [May 18 07:39:19] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) DTLS srtp - stopped timeout timer' [May 18 07:39:19] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) DTLS stop [May 18 07:39:19] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) DTLS srtp - stopped timeout timer' [May 18 07:39:19] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) DTLS srtp - stopped timeout timer' [May 18 07:39:19] DEBUG[20189] res_rtp_asterisk.c: (0x7f5b481044c0) ICE RTP transport deallocating [May 18 07:39:19] DEBUG[20189] rtp_engine.c: Destroyed RTP instance '0x7f5b481044c0' [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: [May 18 07:39:19] DEBUG[20189] channel.c: Channel 0x7f5b48173f00 'PJSIP/sip_client-00000001' destroying [May 18 07:39:19] DEBUG[20189] stasis.c: Destroying topic. name: channel:pbx.example.com-1621337928.2, detail: [May 18 07:39:19] DEBUG[20189] stasis.c: Topic 'channel:pbx.example.com-1621337928.2': 0x7f5b481037a0 destroyed [May 18 07:39:19] DEBUG[20189] channel_internal_api.c: : MultistreamFormats: (nothing) [May 18 07:39:19] DEBUG[20189] channel_internal_api.c: Channel is being initialized or destroyed [May 18 07:39:19] DEBUG[20189] chan_pjsip.c: [May 18 07:39:19] DEBUG[19082] devicestate.c: No provider found, checking channel drivers for PJSIP - sip_client [May 18 07:39:19] DEBUG[19082] devicestate.c: Changing state for PJSIP/sip_client - state 1 (Not in use) [May 18 07:39:19] DEBUG[19093] cdr.c: Finalized CDR for PJSIP/sip_client-00000001 - start 1621337928.365010 answer 1621337928.366395 end 1621337959.117836 dur 30.752 bill 30.751 dispo ANSWERED [May 18 07:39:19] DEBUG[19093] stasis.c: Creating topic. name: channel:pbx.example.com-1621337959.3, detail: [May 18 07:39:19] DEBUG[19093] stasis.c: Topic 'channel:pbx.example.com-1621337959.3': 0x7f5b58007e70 created [May 18 07:39:19] DEBUG[19093] stasis.c: Destroying topic. name: channel:pbx.example.com-1621337959.3, detail: [May 18 07:39:19] DEBUG[19093] stasis.c: Topic 'channel:pbx.example.com-1621337959.3': 0x7f5b58007e70 destroyed [May 18 07:39:19] DEBUG[19211] app_queue.c: Device 'PJSIP/sip_client' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 07:39:19] DEBUG[19102] res_pjsip_session.c: sip_client TSX State: Terminated Inv State: DISCONNCTD [May 18 07:39:19] DEBUG[19102] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [May 18 07:39:19] DEBUG[19102] res_pjsip_session.c: The state change pertains to the endpoint 'sip_client()' [May 18 07:39:19] DEBUG[19102] res_pjsip_session.c: The inv session does NOT have an invite_tsx [May 18 07:39:19] DEBUG[19102] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7f5b800fc3c8 [May 18 07:39:19] DEBUG[19102] res_pjsip_session.c: The current transaction state is Terminated [May 18 07:39:19] DEBUG[19102] res_pjsip_session.c: The transaction state change event is TIMER [May 18 07:39:19] DEBUG[19102] res_pjsip_session.c: The current inv state is DISCONNCTD [May 18 07:39:19] DEBUG[19102] res_pjsip_session.c: Disconnected [May 18 07:39:19] DEBUG[19102] res_pjsip_session.c: (null session) TSX State: Terminated Inv State: DISCONNCTD [May 18 07:39:19] DEBUG[19102] res_pjsip_session.c: [May 18 07:39:19] DEBUG[20189] res_pjsip_session.c: sip_client: Destroying SIP session [May 18 07:39:21] DEBUG[19113] res_pjsip_registrar.c: Woke up at 1621337961 Interval: 30 [May 18 07:39:21] DEBUG[19113] res_pjsip_registrar.c: Expiring 0 contacts