[Nov 9 07:07:45] DEBUG[3597] pbx_spool.c: Filename: /var/spool/asterisk/outgoing/apicall.bd3b52eb-1398-451b-9fb7-7fc3630493b1, Retries: 0, max: 0 [Nov 9 07:07:45] DEBUG[3597] pbx_spool.c: Outgoing Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1: StartRetry [Nov 9 07:07:45] VERBOSE[19610] pbx_spool.c: Attempting call on Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 for bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg2:1 (Retry 1) [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: : Formats: (none) [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 07:07:45] DEBUG[19610] stasis.c: Creating topic. name: channel:1667952465.3471, detail: [Nov 9 07:07:45] DEBUG[19610] stasis.c: Topic 'channel:1667952465.3471': 0x7fa28406ff60 created [Nov 9 07:07:45] DEBUG[19610] channel.c: Channel 0x7fa28406b610 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1' allocated [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1: MultistreamFormats: (slin) [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: Set native formats but not topology [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1: <0:audio-0:audio:sendrecv (slin)> [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: Used provided topology [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: : Formats: (none) [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 07:07:45] DEBUG[19610] stasis.c: Creating topic. name: channel:1667952465.3472, detail: [Nov 9 07:07:45] DEBUG[19610] stasis.c: Topic 'channel:1667952465.3472': 0x7fa2840bf680 created [Nov 9 07:07:45] DEBUG[19610] channel.c: Channel 0x7fa284018390 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' allocated [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2: MultistreamFormats: (slin) [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: Set native formats but not topology [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2: <0:audio-0:audio:sendrecv (slin)> [Nov 9 07:07:45] DEBUG[19610] channel_internal_api.c: Used provided topology [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx.c: Launching 'AGI' [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] pbx.c: Executing [bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1:1] AGI("Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2", "agi://127.0.0.1/dial") in new stack [Nov 9 07:07:45] DEBUG[19611][C-0000077a] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 07:07:45] DEBUG[19611][C-0000077a] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 07:07:45] VERBOSE[19610] dial.c: Called bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] res_agi.c: Wow, connected! [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'txnId' is 'bd3b52eb-1398-451b-9fb7-7fc3630493b1' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'CHANNEL' is 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_stack.c: Gosub args:api_ivr_leg1,leghangup,1 new_args:api_ivr_leg1,leghangup,1 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'txnId' is 'bd3b52eb-1398-451b-9fb7-7fc3630493b1' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'CONTEXT' is 'api_ivr_leg1' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'container_uuid' is '9cfda032-edb1-4128-917d-db13ce5ece60' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'ringback_music' is NULL [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] res_agi.c: AGI Script Executing Application: (GOTO) Options: (attempt,1) [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] pbx_builtins.c: Goto (api_ivr_leg1,attempt,1) [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] res_agi.c: AGI Script agi://127.0.0.1/dial completed, returning 0 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'dialStr' is 'PJSIP/outgoing@kamailio' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'ringtime' is '15' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Expression result is '1' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'ringtime' is '15' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Function IF(1?15:) result is '15' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'dialOpt' is 'it' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Expression result is '1' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'dialOpt' is 'it' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Function IF(1?it:) result is 'it' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'CONTEXT' is 'api_ivr_leg1' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx.c: Launching 'Dial' [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] pbx.c: Executing [attempt@api_ivr_leg1:1] Dial("Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2", "PJSIP/outgoing@kamailio,15,itb(api_ivr_leg1^callee_handler^1)") in new stack [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_dial.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2: Data: PJSIP/outgoing@kamailio,15,itb(api_ivr_leg1^callee_handler^1) [Nov 9 07:07:45] DEBUG[19611][C-0000077a] chan_pjsip.c: outgoing@kamailio Topology: <0:audio-0:audio:sendrecv (slin)> [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: outgoing@kamailio [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: kamailio outgoing Topology: <0:audio-0:audio:sendrecv (slin)> [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: kamailio [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: Direct media no glare mitigation [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session/pjsip_session_caps.c: 'kamailio' Caps for outgoing audio call with pref 'remote_merge' - remote: (slin) local: (alaw|opus|ulaw|g729|gsm) joint: (alaw|opus|ulaw|g729|gsm) [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: [Nov 9 07:07:45] DEBUG[19611][C-0000077a] chan_pjsip.c: kamailio [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel_internal_api.c: : Formats: (none) [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 07:07:45] DEBUG[19611][C-0000077a] stasis.c: Creating topic. name: channel:1667952465.3473, detail: [Nov 9 07:07:45] DEBUG[19611][C-0000077a] stasis.c: Topic 'channel:1667952465.3473': 0x7fa29000db50 created [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Channel 0x7fa290006740 'PJSIP/kamailio-000000ae' allocated [Nov 9 07:07:45] DEBUG[19611][C-0000077a] chan_pjsip.c: Topology: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> Formats: (alaw|opus|ulaw|g729|gsm) [Nov 9 07:07:45] DEBUG[19611][C-0000077a] chan_pjsip.c: Compatible? yes [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel_internal_api.c: PJSIP/kamailio-000000ae: MultistreamFormats: (alaw|opus|ulaw|g729|gsm) [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel_internal_api.c: Set native formats but not topology [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel_internal_api.c: PJSIP/kamailio-000000ae: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel_internal_api.c: Used provided topology [Nov 9 07:07:45] DEBUG[19611][C-0000077a] chan_pjsip.c: [Nov 9 07:07:45] DEBUG[19611][C-0000077a] chan_pjsip.c: Channel: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[19611][C-0000077a] rtp_engine.c: Can't find native functions for channel 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Inheriting variable dstLegId from Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 to PJSIP/kamailio-000000ae. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Inheriting variable __container_uuid from Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 to PJSIP/kamailio-000000ae. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Inheriting variable __txnId from Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 to PJSIP/kamailio-000000ae. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_stack.c: Gosub args:api_ivr_leg1,callee_handler,1 new_args:api_ivr_leg1,callee_handler,1 [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] app_stack.c: PJSIP/kamailio-000000ae Internal Gosub(api_ivr_leg1,callee_handler,1) start [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_stack.c: PJSIP/kamailio-000000ae Original location: internal,attempt,1 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_stack.c: Channel PJSIP/kamailio-000000ae has no datastore, so we're allocating one. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_stack.c: Gosub exited with status 0 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx.c: Launching 'AGI' [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] pbx.c: Executing [callee_handler@api_ivr_leg1:1] AGI("PJSIP/kamailio-000000ae", "agi://127.0.0.1/callee_predial") in new stack [Nov 9 07:07:45] DEBUG[19611][C-0000077a] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 07:07:45] DEBUG[19611][C-0000077a] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] res_agi.c: Wow, connected! [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'dstLegId' is 'c5cc010d-baf0-4020-b34b-daea453d2655' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_stack.c: Gosub args:api_ivr_leg1,leghangup,1 new_args:api_ivr_leg1,leghangup,1 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'txnId' is 'bd3b52eb-1398-451b-9fb7-7fc3630493b1' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'CHANNEL' is 'PJSIP/kamailio-000000ae' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'container_uuid' is '9cfda032-edb1-4128-917d-db13ce5ece60' [Nov 9 07:07:45] ERROR[2888] res_pjsip_header_funcs.c: No headers had been previously added to this session. [Nov 9 07:07:45] DEBUG[2131] res_pjsip_header_funcs.c: Adding header X-header-TxnId with value bd3b52eb-1398-451b-9fb7-7fc3630493b1 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_header_funcs.c: Adding header X-header-LegId with value c5cc010d-baf0-4020-b34b-daea453d2655 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_header_funcs.c: Adding header X-header-FOLLOWME with value sip [Nov 9 07:07:45] DEBUG[2131] res_pjsip_header_funcs.c: Adding header X-header-RPEER with value sip8673168 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_header_funcs.c: Adding header X-header-SERVER-PORT with value 5060 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_header_funcs.c: Adding header X-header-DOMAIN with value siptest.b3networks.com [Nov 9 07:07:45] DEBUG[2131] res_pjsip_header_funcs.c: Adding header X-header-Vendor with value SIPTESTB3 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_header_funcs.c: Adding header X-header-R_DNIS with value RR [Nov 9 07:07:45] DEBUG[2131] res_pjsip_header_funcs.c: Adding header X-header-R_CLID with value +61390084223 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_header_funcs.c: Adding header X-header-R_CLINAME with value 61390084223 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] config.c: extract int from [10] in [-2147483648, 2147483647] gives [10](0) [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] res_agi.c: AGI Script agi://127.0.0.1/callee_predial completed, returning 0 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] pbx.c: Launching 'Return' [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] pbx.c: Executing [callee_handler@api_ivr_leg1:2] Return("PJSIP/kamailio-000000ae", "") in new stack [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_stack.c: Spawn extension (internal,attempt,1) exited with -1 on 'PJSIP/kamailio-000000ae' [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] app_stack.c: Spawn extension (internal, attempt, 1) exited non-zero on 'PJSIP/kamailio-000000ae' [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] app_stack.c: PJSIP/kamailio-000000ae Internal Gosub(api_ivr_leg1,callee_handler,1) complete GOSUB_RETVAL= [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_stack.c: PJSIP/kamailio-000000ae Ending location: internal,attempt,1 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] chan_pjsip.c: PJSIP/kamailio-000000ae Topology: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> [Nov 9 07:07:45] DEBUG[19611][C-0000077a] chan_pjsip.c: 'call' task pushed [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] app_dial.c: Called PJSIP/outgoing@kamailio [Nov 9 07:07:45] DEBUG[2888] chan_pjsip.c: PJSIP/kamailio-000000ae Topology: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_dial.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Processing streams [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Channel PJSIP/kamailio-000000ae setting read format path: alaw -> slin [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Processing stream 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 setting write format path: slin -> slin [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae Adding position 0 [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Creating new media session [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Setting media session as default for audio [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 setting read format path: slin -> slin [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Done [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae Stream: 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Channel PJSIP/kamailio-000000ae setting write format path: slin -> alaw [Nov 9 07:07:45] DEBUG[2888] res_pjsip_sdp_rtp.c: PJSIP/kamailio-000000ae Type: audio 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) [Nov 9 07:07:45] DEBUG[2888] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7fa2940355d0' [Nov 9 07:07:45] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) RTP allocated port 21432 [Nov 9 07:07:45] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) ICE creating session [::]:21432 (21432) [Nov 9 07:07:45] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) ICE create [Nov 9 07:07:45] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) ICE add system candidates [Nov 9 07:07:45] DEBUG[2888] netsock2.c: Splitting '172.21.144.120' into... [Nov 9 07:07:45] DEBUG[2888] netsock2.c: ...host '172.21.144.120' and port ''. [Nov 9 07:07:45] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) ICE add candidate: 172.21.144.120:21432, 2130706431 [Nov 9 07:07:45] DEBUG[2888] netsock2.c: Splitting 'fe80::6:fcff:feb9:712a' into... [Nov 9 07:07:45] DEBUG[2888] netsock2.c: ...host 'fe80::6:fcff:feb9:712a' and port ''. [Nov 9 07:07:45] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) ICE add candidate: [fe80::6:fcff:feb9:712a]:21432, 2130706431 [Nov 9 07:07:45] DEBUG[2888] rtp_engine.c: RTP instance '0x7fa2940355d0' is setup and ready to go [Nov 9 07:07:45] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) ICE stopped [Nov 9 07:07:45] DEBUG[2888] netsock2.c: Splitting 'tsworker1' into... [Nov 9 07:07:45] DEBUG[2888] netsock2.c: ...host 'tsworker1' and port ''. [Nov 9 07:07:45] DEBUG[2888] acl.c: Multiple addresses. Using the first only [Nov 9 07:07:45] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) RTCP setup on RTP instance [Nov 9 07:07:45] DEBUG[2888] res_pjsip_sdp_rtp.c: RC: 1 [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Handled [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Stream 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) added [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Done with 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Adding bundle groups (if available) [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Copying connection details [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Processing media 0 [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Media 0 reset [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Method is INVITE [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2888] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '172.21.144.120' [Nov 9 07:07:45] DEBUG[2888] res_pjsip/pjsip_resolver.c: Transport type for target '172.21.144.120' is 'UDP transport' [Nov 9 07:07:45] DEBUG[2888] res_pjsip/pjsip_resolver.c: Target '172.21.144.120' is an IP address, skipping resolution [Nov 9 07:07:45] DEBUG[2888] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to 172.21.144.120:5060 (this may be re-written again later) [Nov 9 07:07:45] DEBUG[2888] netsock2.c: Splitting '172.21.144.120' into... [Nov 9 07:07:45] DEBUG[2888] netsock2.c: ...host '172.21.144.120' and port ''. [Nov 9 07:07:45] DEBUG[2888] res_pjsip_nat.c: Request is being sent to local address, skipping NAT manipulation [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae Event: TSX_STATE Inv State: CALLING [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ae)' [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fa294141ec8) [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The current inv state is CALLING [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Source of transaction state change is TX_MSG [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Calling Inv State: CALLING [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ae)' [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fa294141ec8) [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fa294141ec8 [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The current transaction state is Calling [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The transaction state change event is TX_MSG [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The current inv state is CALLING [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Calling Inv State: CALLING [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Topology: Pending: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> Active: (null topology) [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[2888] chan_pjsip.c: RC: 0 [Nov 9 07:07:45] DEBUG[3553] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7fa2880c9bb8 for Response msg 100/INVITE/cseq=23988 (rdata0x7fa2a0001108) [Nov 9 07:07:45] DEBUG[3553] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/kamailio-00000620 associated with dialog dlg0x7fa2880c9bb8 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae Method: INVITE Status: 100 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Proceeding Inv State: CALLING [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ae)' [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fa294141ec8) [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fa294141ec8 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The current transaction state is Proceeding [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The transaction state change event is RX_MSG [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The current inv state is CALLING [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae: Response is 100 Trying [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae: Status: 100 [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae: Not queueing anything [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae: Status: 100 [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Proceeding Inv State: CALLING [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: Topology: Pending: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> Active: (null topology) [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[3553] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7fa2880c9bb8 for Response msg 180/INVITE/cseq=23988 (rdata0x7fa2a0001108) [Nov 9 07:07:45] DEBUG[3553] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/kamailio-00000620 associated with dialog dlg0x7fa2880c9bb8 [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae Method: INVITE Status: 180 [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae Event: TSX_STATE Inv State: EARLY [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ae)' [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fa294141ec8) [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The current inv state is EARLY [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Source of transaction state change is RX_MSG [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Received response [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Response is 180 Ringing [Nov 9 07:07:45] DEBUG[2888] chan_pjsip.c: PJSIP/kamailio-000000ae: Status: 180 [Nov 9 07:07:45] DEBUG[2888] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Proceeding Inv State: EARLY [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ae)' [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fa294141ec8) [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fa294141ec8 [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The current transaction state is Proceeding [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The transaction state change event is RX_MSG [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: The current inv state is EARLY [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae: Response is 180 Ringing [Nov 9 07:07:45] DEBUG[2888] chan_pjsip.c: PJSIP/kamailio-000000ae: Status: 180 [Nov 9 07:07:45] DEBUG[2888] chan_pjsip.c: PJSIP/kamailio-000000ae: Queueing RINGING [Nov 9 07:07:45] DEBUG[2888] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2888] chan_pjsip.c: PJSIP/kamailio-000000ae: Status: 180 [Nov 9 07:07:45] DEBUG[2888] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Proceeding Inv State: EARLY [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: Topology: Pending: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> Active: (null topology) [Nov 9 07:07:45] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for PJSIP - kamailio [Nov 9 07:07:45] DEBUG[3528] devicestate.c: Changing state for PJSIP/kamailio - state 7 (Ring+Inuse) [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] app_dial.c: PJSIP/kamailio-000000ae is ringing [Nov 9 07:07:45] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for Local - bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 [Nov 9 07:07:45] DEBUG[3528] devicestate.c: Changing state for Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 - state 2 (In use) [Nov 9 07:07:45] VERBOSE[19610] dial.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 is ringing [Nov 9 07:07:45] DEBUG[3553] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7fa2880c9bb8 for Response msg 200/INVITE/cseq=23988 (rdata0x7fa2a0001108) [Nov 9 07:07:45] DEBUG[3553] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/kamailio-00000620 associated with dialog dlg0x7fa2880c9bb8 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae Method: INVITE Status: 200 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae Event: TSX_STATE Inv State: CONNECTING [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ae)' [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fa294141ec8) [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The current inv state is CONNECTING [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae: Source of transaction state change is RX_MSG [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae: Received response [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae: Response is 200 OK [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae: Status: 200 [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae: Applying negotiated SDP media stream 'audio' using audio SDP handler [Nov 9 07:07:45] DEBUG[2131] res_pjsip_sdp_rtp.c: PJSIP/kamailio-000000ae Stream: 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) [Nov 9 07:07:45] DEBUG[2131] res_rtp_asterisk.c: (0x7fa2940355d0) RTCP ignoring duplicate property [Nov 9 07:07:45] DEBUG[2131] netsock2.c: Splitting '172.21.32.116' into... [Nov 9 07:07:45] DEBUG[2131] netsock2.c: ...host '172.21.32.116' and port ''. [Nov 9 07:07:45] DEBUG[2131] acl.c: For destination '172.21.32.116', our source address is '172.21.144.120'. [Nov 9 07:07:45] DEBUG[2131] res_rtp_asterisk.c: (0x7fa2940355d0) RTCP setting address on RTP instance [Nov 9 07:07:45] DEBUG[2131] res_pjsip_sdp_rtp.c: PJSIP/kamailio-000000ae ANSWER [Nov 9 07:07:45] DEBUG[2131] res_pjsip_sdp_rtp.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7fa2c249ce00 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_sdp_rtp.c: [Nov 9 07:07:45] DEBUG[2131] rtp_engine.c: Copying tx payload mapping 8 (0x7fa284070ff8) from 0x7fa2c249ce00 to 0x7fa2940357a8 [Nov 9 07:07:45] DEBUG[2131] rtp_engine.c: Copying tx payload mapping 101 (0x7fa284010ce8) from 0x7fa2c249ce00 to 0x7fa2940357a8 [Nov 9 07:07:45] DEBUG[2131] channel_internal_api.c: PJSIP/kamailio-000000ae: MultistreamFormats: (alaw) [Nov 9 07:07:45] DEBUG[2131] channel_internal_api.c: Set native formats but not topology [Nov 9 07:07:45] DEBUG[2131] res_pjsip_sdp_rtp.c: [Nov 9 07:07:45] DEBUG[2131] res_rtp_asterisk.c: (0x7fa2940355d0) DTLS - ast_rtp_activate rtp=0x7fa294051c50 - setup and perform DTLS' [Nov 9 07:07:45] DEBUG[2131] res_rtp_asterisk.c: (0x7fa294051c50) DTLS perform handshake - ssl = (nil), setup = 0 [Nov 9 07:07:45] DEBUG[2131] res_rtp_asterisk.c: (0x7fa294051c50) DTLS perform handshake - ssl = (nil), setup = 0 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_sdp_rtp.c: Handled [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae: Applied negotiated SDP media stream 'audio' using audio SDP handler [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae: Applied negotiated SDP media stream 'audio' using audio SDP handler [Nov 9 07:07:45] DEBUG[2131] channel_internal_api.c: PJSIP/kamailio-000000ae: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 07:07:45] DEBUG[2131] channel_internal_api.c: Used provided topology [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '172.21.144.120' [Nov 9 07:07:45] DEBUG[2131] res_pjsip/pjsip_resolver.c: Transport type for target '172.21.144.120' is 'UDP transport' [Nov 9 07:07:45] DEBUG[2131] res_pjsip/pjsip_resolver.c: Target '172.21.144.120' is an IP address, skipping resolution [Nov 9 07:07:45] DEBUG[2131] netsock2.c: Splitting '172.21.144.120' into... [Nov 9 07:07:45] DEBUG[2131] netsock2.c: ...host '172.21.144.120' and port ''. [Nov 9 07:07:45] DEBUG[2131] res_pjsip_nat.c: Request is being sent to local address, skipping NAT manipulation [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae Event: TX_MSG Inv State: CONFIRMED [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_state_changed called on event TX_MSG [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ae)' [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The inv session still has an invite_tsx (0x7fa294141ec8) [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The current inv state is CONFIRMED [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Terminated Inv State: CONFIRMED [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ae)' [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fa294141ec8 [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The current transaction state is Terminated [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The transaction state change event is RX_MSG [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: The current inv state is CONFIRMED [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae: Response is 200 OK [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae: Status: 200 [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae: Queueing ANSWER [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae: Status: 200 [Nov 9 07:07:45] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Terminated Inv State: CONFIRMED [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 07:07:45] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_dial.c: PJSIP/kamailio-000000ae answered Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] app_dial.c: PJSIP/kamailio-000000ae answered Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] app_dial.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2: Answered by PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 setting write format path: slin -> slin [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 setting read format path: slin -> slin [Nov 9 07:07:45] DEBUG[19611][C-0000077a] core_unreal.c: Blocked indication -1 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] stasis.c: Creating topic. name: bridge:all/bridge:4af0a403-5498-4541-b6f9-cb85951927a3, detail: [Nov 9 07:07:45] DEBUG[19611][C-0000077a] stasis.c: Topic 'bridge:all/bridge:4af0a403-5498-4541-b6f9-cb85951927a3': 0x7fa290003f50 created [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge_native_rtp.c: Bridge '4af0a403-5498-4541-b6f9-cb85951927a3' can not use native RTP bridge as two channels are required [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Chose bridge technology simple_bridge [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: calling simple_bridge technology constructor [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: calling simple_bridge technology start [Nov 9 07:07:45] DEBUG[19611][C-0000077a] stasis_bridges.c: Update: 0x7fa290014f38 Old: New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:45] DEBUG[3547] stasis_bridges.c: Update: 0x7fa290014f38 Old: New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:45] VERBOSE[19610] dial.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 answered [Nov 9 07:07:45] DEBUG[19610][C-0000077b] pbx.c: Launching 'AGI' [Nov 9 07:07:45] VERBOSE[19610][C-0000077b] pbx.c: Executing [bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg2:1] AGI("Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1", "agi://127.0.0.1/dial") in new stack [Nov 9 07:07:45] DEBUG[19610][C-0000077b] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 07:07:45] DEBUG[19610][C-0000077b] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 07:07:45] DEBUG[19610][C-0000077b] res_agi.c: Wow, connected! [Nov 9 07:07:45] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for PJSIP - kamailio [Nov 9 07:07:45] DEBUG[3528] devicestate.c: Changing state for PJSIP/kamailio - state 2 (In use) [Nov 9 07:07:45] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for Local - bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 [Nov 9 07:07:45] DEBUG[3528] devicestate.c: Changing state for Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 - state 2 (In use) [Nov 9 07:07:45] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for Local - bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 [Nov 9 07:07:45] DEBUG[3528] devicestate.c: Changing state for Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 - state 2 (In use) [Nov 9 07:07:45] DEBUG[19614][C-0000077a] bridge_channel.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: 0x7fa29001a500(PJSIP/kamailio-000000ae) is joining [Nov 9 07:07:45] DEBUG[19614][C-0000077a] bridge_channel.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: pushing 0x7fa29001a500(PJSIP/kamailio-000000ae) [Nov 9 07:07:45] VERBOSE[19614][C-0000077a] bridge_channel.c: Channel PJSIP/kamailio-000000ae joined 'simple_bridge' basic-bridge <4af0a403-5498-4541-b6f9-cb85951927a3> [Nov 9 07:07:45] DEBUG[19614][C-0000077a] stasis_bridges.c: Update: 0x7fa28c0084d8 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:45] DEBUG[19614][C-0000077a] stasis_bridges.c: Update: 0x7fa28c0084d8 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:45] DEBUG[19614][C-0000077a] bridge_native_rtp.c: Bridge '4af0a403-5498-4541-b6f9-cb85951927a3' can not use native RTP bridge as two channels are required [Nov 9 07:07:45] DEBUG[19614][C-0000077a] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 07:07:45] DEBUG[19614][C-0000077a] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 07:07:45] DEBUG[19610][C-0000077b] pbx_variables.c: Result of 'txnId' is 'bd3b52eb-1398-451b-9fb7-7fc3630493b1' [Nov 9 07:07:45] DEBUG[19614][C-0000077a] bridge.c: Bridge technology softmix does not have any capabilities we want. [Nov 9 07:07:45] DEBUG[19614][C-0000077a] bridge.c: Chose bridge technology simple_bridge [Nov 9 07:07:45] DEBUG[19614][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3 is already using the new technology. [Nov 9 07:07:45] DEBUG[19614][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: 0x7fa29001a500(PJSIP/kamailio-000000ae) is joining simple_bridge technology [Nov 9 07:07:45] DEBUG[19610][C-0000077b] pbx_variables.c: Result of 'CHANNEL' is 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1' [Nov 9 07:07:45] DEBUG[19614][C-0000077a] stasis_bridges.c: Update: 0x7fa28c0084d8 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:45] DEBUG[19614][C-0000077a] stasis_bridges.c: Update: 0x7fa28c0084d8 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:45] DEBUG[19614][C-0000077a] chan_pjsip.c: PJSIP/kamailio-000000ae: Indicated Media SSRC change [Nov 9 07:07:45] DEBUG[19614][C-0000077a] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge_channel.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: 0x7fa29000b680(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2) is joining [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge_channel.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: pushing 0x7fa29000b680(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2) [Nov 9 07:07:45] VERBOSE[19611][C-0000077a] bridge_channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 joined 'simple_bridge' basic-bridge <4af0a403-5498-4541-b6f9-cb85951927a3> [Nov 9 07:07:45] DEBUG[19611][C-0000077a] stasis_bridges.c: Update: 0x7fa29000aeb8 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge_native_rtp.c: Bridge '4af0a403-5498-4541-b6f9-cb85951927a3'. Checking compatability for channels 'PJSIP/kamailio-000000ae' and 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge_native_rtp.c: Bridge '4af0a403-5498-4541-b6f9-cb85951927a3' can not use native RTP bridge as could not get details [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Bridge technology softmix does not have any capabilities we want. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Chose bridge technology simple_bridge [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3 is already using the new technology. [Nov 9 07:07:45] DEBUG[19611][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: 0x7fa29000b680(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2) is joining simple_bridge technology [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 setting read format path: slin -> slin [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 setting write format path: slin -> slin [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2: Topologies already match. Current: <0:audio-0:audio:sendrecv (slin)> Requested: <0:audio-0:audio:sendrecv (slin)> [Nov 9 07:07:45] DEBUG[19611][C-0000077a] channel.c: PJSIP/kamailio-000000ae: Topologies already match. Current: <0:audio-0:audio:sendrecv (alaw)> Requested: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 07:07:45] DEBUG[19611][C-0000077a] stasis_bridges.c: Update: 0x7fa290018c68 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:45] DEBUG[3547] stasis_bridges.c: Update: 0x7fa29000aeb8 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:45] DEBUG[3547] stasis_bridges.c: Update: 0x7fa290018c68 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:45] DEBUG[19610][C-0000077b] app_stack.c: Gosub args:api_ivr_leg2,leghangup,1 new_args:api_ivr_leg2,leghangup,1 [Nov 9 07:07:45] DEBUG[19610][C-0000077b] pbx_variables.c: Result of 'legId' is 'Local-api_ivr_leg2-bd3b52eb-1398-451b-9fb7-7fc3630493b1' [Nov 9 07:07:45] DEBUG[19610][C-0000077b] pbx_variables.c: Result of 'CONTEXT' is 'api_ivr_leg2' [Nov 9 07:07:45] DEBUG[19610][C-0000077b] pbx_variables.c: Result of 'CONTEXT' is 'api_ivr_leg2' [Nov 9 07:07:45] VERBOSE[19610][C-0000077b] res_agi.c: AGI Script Executing Application: (BRIDGE) Options: (PJSIP/tssbc1_vendor-000000ad,x) [Nov 9 07:07:45] DEBUG[19610][C-0000077b] stasis.c: Creating topic. name: bridge:all/bridge:e8f6bad8-f952-4e77-97ad-4053441a0204, detail: [Nov 9 07:07:45] DEBUG[19610][C-0000077b] stasis.c: Topic 'bridge:all/bridge:e8f6bad8-f952-4e77-97ad-4053441a0204': 0x7fa28411d260 created [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge_native_rtp.c: Bridge 'e8f6bad8-f952-4e77-97ad-4053441a0204' can not use native RTP bridge as two channels are required [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Chose bridge technology simple_bridge [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: calling simple_bridge technology constructor [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: calling simple_bridge technology start [Nov 9 07:07:45] DEBUG[19610][C-0000077b] stasis_bridges.c: Update: 0x7fa28406ea98 Old: New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel_internal_api.c: : Formats: (none) [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 07:07:45] DEBUG[19610][C-0000077b] stasis.c: Creating topic. name: channel:1667952465.3474, detail: [Nov 9 07:07:45] DEBUG[3547] stasis_bridges.c: Update: 0x7fa28406ea98 Old: New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:45] DEBUG[19610][C-0000077b] stasis.c: Topic 'channel:1667952465.3474': 0x7fa28411ed60 created [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Channel 0x7fa284015010 'Surrogate/PJSIP/tssbc1_vendor-000000ad' allocated [Nov 9 07:07:45] DEBUG[19610][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad: Indicated Masquerade notify [Nov 9 07:07:45] DEBUG[19610][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Actually Masquerading PJSIP/tssbc1_vendor-000000ad(6) into the structure of Surrogate/PJSIP/tssbc1_vendor-000000ad(0) [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel_internal_api.c: PJSIP/tssbc1_vendor-000000ad: MultistreamFormats: (alaw) [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel_internal_api.c: Set native formats but not topology [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Channel PJSIP/tssbc1_vendor-000000ad setting write format path: gsm -> alaw [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Channel PJSIP/tssbc1_vendor-000000ad setting read format path: alaw -> alaw [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Putting channel PJSIP/tssbc1_vendor-000000ad in gsm/alaw formats [Nov 9 07:07:45] DEBUG[19610][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad: Indicated Masquerade notify [Nov 9 07:07:45] DEBUG[19610][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Done Masquerading PJSIP/tssbc1_vendor-000000ad (6) [Nov 9 07:07:45] DEBUG[19610][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad: Indicated Media SSRC change [Nov 9 07:07:45] DEBUG[19604][C-00000779] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 9 07:07:45] DEBUG[19610][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad [Nov 9 07:07:45] DEBUG[19604][C-00000779] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 9 07:07:45] DEBUG[19604][C-00000779] channel.c: Channel Surrogate/PJSIP/tssbc1_vendor-000000ad setting write format path: alaw -> alaw [Nov 9 07:07:45] DEBUG[19604][C-00000779] pbx.c: Extension onpause, priority 1 returned normally even though call was hung up [Nov 9 07:07:45] DEBUG[19604][C-00000779] channel.c: Soft-Hanging (0x10) up channel 'Surrogate/PJSIP/tssbc1_vendor-000000ad' [Nov 9 07:07:45] DEBUG[19604][C-00000779] channel.c: Channel 0x7fa2841227e0 'Surrogate/PJSIP/tssbc1_vendor-000000ad' hanging up. Refs: 3 [Nov 9 07:07:45] DEBUG[19617][C-0000077b] bridge_channel.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: 0x7fa28403a520(PJSIP/tssbc1_vendor-000000ad) is joining [Nov 9 07:07:45] DEBUG[19617][C-0000077b] bridge_channel.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: pushing 0x7fa28403a520(PJSIP/tssbc1_vendor-000000ad) [Nov 9 07:07:45] VERBOSE[19617][C-0000077b] bridge_channel.c: Channel PJSIP/tssbc1_vendor-000000ad joined 'simple_bridge' basic-bridge [Nov 9 07:07:45] DEBUG[19617][C-0000077b] stasis_bridges.c: Update: 0x7fa298003d78 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:45] DEBUG[19617][C-0000077b] stasis_bridges.c: Update: 0x7fa298003d78 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:45] DEBUG[19617][C-0000077b] bridge_native_rtp.c: Bridge 'e8f6bad8-f952-4e77-97ad-4053441a0204' can not use native RTP bridge as two channels are required [Nov 9 07:07:45] DEBUG[19617][C-0000077b] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 07:07:45] DEBUG[19617][C-0000077b] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 07:07:45] DEBUG[19617][C-0000077b] bridge.c: Bridge technology softmix does not have any capabilities we want. [Nov 9 07:07:45] DEBUG[19617][C-0000077b] bridge.c: Chose bridge technology simple_bridge [Nov 9 07:07:45] DEBUG[19617][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204 is already using the new technology. [Nov 9 07:07:45] DEBUG[19617][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: 0x7fa28403a520(PJSIP/tssbc1_vendor-000000ad) is joining simple_bridge technology [Nov 9 07:07:45] DEBUG[19617][C-0000077b] stasis_bridges.c: Update: 0x7fa298014b38 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:45] DEBUG[19617][C-0000077b] stasis_bridges.c: Update: 0x7fa298014b38 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:45] DEBUG[19617][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad: Indicated Media SSRC change [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Channel 0x7fa2841227e0 'Surrogate/PJSIP/tssbc1_vendor-000000ad' destroying [Nov 9 07:07:45] DEBUG[19617][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad [Nov 9 07:07:45] DEBUG[19610][C-0000077b] stasis.c: Destroying topic. name: channel:1667952465.3474, detail: [Nov 9 07:07:45] DEBUG[19610][C-0000077b] stasis.c: Topic 'channel:1667952465.3474': 0x7fa28411ed60 destroyed [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel_internal_api.c: : Formats: (nothing) [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 07:07:45] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for Surrogate - PJSIP/tssbc1_vendor [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge_channel.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: 0x7fa28410cad0(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1) is joining [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge_channel.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: pushing 0x7fa28410cad0(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1) [Nov 9 07:07:45] VERBOSE[19610][C-0000077b] bridge_channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 joined 'simple_bridge' basic-bridge [Nov 9 07:07:45] DEBUG[19610][C-0000077b] stasis_bridges.c: Update: 0x7fa28406ea98 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:45] DEBUG[3528] devicestate.c: Changing state for Surrogate/PJSIP/tssbc1_vendor - state 0 (Unknown) [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge_native_rtp.c: Bridge 'e8f6bad8-f952-4e77-97ad-4053441a0204'. Checking compatability for channels 'PJSIP/tssbc1_vendor-000000ad' and 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1' [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge_native_rtp.c: Bridge 'e8f6bad8-f952-4e77-97ad-4053441a0204' can not use native RTP bridge as could not get details [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Bridge technology softmix does not have any capabilities we want. [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Chose bridge technology simple_bridge [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204 is already using the new technology. [Nov 9 07:07:45] DEBUG[19610][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: 0x7fa28410cad0(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1) is joining simple_bridge technology [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 setting read format path: slin -> slin [Nov 9 07:07:45] DEBUG[3547] stasis_bridges.c: Update: 0x7fa28406ea98 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Channel PJSIP/tssbc1_vendor-000000ad setting write format path: slin -> alaw [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Channel PJSIP/tssbc1_vendor-000000ad setting read format path: alaw -> slin [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 setting write format path: slin -> slin [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1: Topologies already match. Current: <0:audio-0:audio:sendrecv (slin)> Requested: <0:audio-0:audio:sendrecv (slin)> [Nov 9 07:07:45] DEBUG[19610][C-0000077b] channel.c: PJSIP/tssbc1_vendor-000000ad: Topologies already match. Current: <0:audio-0:audio:sendrecv (alaw)> Requested: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 07:07:45] DEBUG[19610][C-0000077b] stasis_bridges.c: Update: 0x7fa2840179e8 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:45] DEBUG[3547] stasis_bridges.c: Update: 0x7fa2840179e8 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:45] DEBUG[19617][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad: Indicated Connected line update [Nov 9 07:07:45] DEBUG[19617][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad [Nov 9 07:07:45] DEBUG[19614][C-0000077a] chan_pjsip.c: PJSIP/kamailio-000000ae: Indicated Media SSRC change [Nov 9 07:07:45] DEBUG[19614][C-0000077a] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:45] DEBUG[19614][C-0000077a] chan_pjsip.c: PJSIP/kamailio-000000ae: Indicated Connected line update [Nov 9 07:07:45] DEBUG[19614][C-0000077a] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:49] DEBUG[3553] res_pjsip/pjsip_distributor.c: Could not find matching transaction for Request msg OPTIONS/cseq=58915241 (rdata0x7fa2a0001108) [Nov 9 07:07:49] DEBUG[3553] res_pjsip/pjsip_distributor.c: Calculated serializer pjsip/distributor-0000002b to use for Request msg OPTIONS/cseq=58915241 (rdata0x7fa2a0001108) [Nov 9 07:07:49] DEBUG[2888] netsock2.c: Splitting '172.21.32.116' into... [Nov 9 07:07:49] DEBUG[2888] netsock2.c: ...host '172.21.32.116' and port ''. [Nov 9 07:07:49] DEBUG[2888] res_pjsip_endpoint_identifier_ip.c: Source address 172.21.32.116:5050 does not match identify 'kamailio' [Nov 9 07:07:49] DEBUG[2888] res_pjsip_endpoint_identifier_ip.c: Source address 172.21.32.116:5050 matches identify 'tssbc1_stack' [Nov 9 07:07:49] DEBUG[2888] res_pjsip_endpoint_identifier_ip.c: Identify 'tssbc1_stack' SIP message matched to endpoint tssbc1_stack [Nov 9 07:07:49] DEBUG[2888] netsock2.c: Splitting '172.21.32.116' into... [Nov 9 07:07:49] DEBUG[2888] netsock2.c: ...host '172.21.32.116' and port ''. [Nov 9 07:07:50] DEBUG[3597] pbx_spool.c: Filename: /var/spool/asterisk/outgoing/apicall.bd3b52eb-1398-451b-9fb7-7fc3630493b1, Retries: 0, max: 0 [Nov 9 07:07:50] DEBUG[3597] pbx_spool.c: Outgoing Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1: DelayedRetry [Nov 9 07:07:50] DEBUG[3597] pbx_spool.c: Delaying retry since we're currently running '/var/spool/asterisk/outgoing/apicall.bd3b52eb-1398-451b-9fb7-7fc3630493b1' [Nov 9 07:07:50] DEBUG[3553] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7fa2880c9bb8 for Request msg BYE/cseq=59422443 (rdata0x7fa2a0001108) [Nov 9 07:07:50] DEBUG[3553] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/kamailio-00000620 associated with dialog dlg0x7fa2880c9bb8 [Nov 9 07:07:50] DEBUG[2131] netsock2.c: Splitting '172.21.144.120' into... [Nov 9 07:07:50] DEBUG[2131] netsock2.c: ...host '172.21.144.120' and port ''. [Nov 9 07:07:50] DEBUG[2131] res_pjsip_nat.c: Request is being sent to local address, skipping NAT manipulation [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Completed Inv State: CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ae)' [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7fa28411c7a8 [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current transaction state is Completed [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The transaction state change event is TX_MSG [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current inv state is CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Completed Inv State: CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae Event: TSX_STATE Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ae)' [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current inv state is DISCONNCTD [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae: Source of transaction state change is RX_MSG [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae: Received request [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae: Method is BYE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Completed Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ae)' [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x7fa28411c7a8 [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current transaction state is Completed [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The transaction state change event is RX_MSG [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current inv state is DISCONNCTD [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ae TSX State: Completed Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:50] DEBUG[2131] chan_pjsip.c: [Nov 9 07:07:50] DEBUG[19614][C-0000077a] bridge_channel.c: Setting 0x7fa29001a500(PJSIP/kamailio-000000ae) state from:0 to:1 [Nov 9 07:07:50] DEBUG[19614][C-0000077a] bridge_channel.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: pulling 0x7fa29001a500(PJSIP/kamailio-000000ae) [Nov 9 07:07:50] VERBOSE[19614][C-0000077a] bridge_channel.c: Channel PJSIP/kamailio-000000ae left 'simple_bridge' basic-bridge <4af0a403-5498-4541-b6f9-cb85951927a3> [Nov 9 07:07:50] DEBUG[19614][C-0000077a] bridge_channel.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: 0x7fa29001a500(PJSIP/kamailio-000000ae) is leaving simple_bridge technology [Nov 9 07:07:50] DEBUG[19614][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: dissolving bridge with cause 16(Normal Clearing) [Nov 9 07:07:50] DEBUG[19614][C-0000077a] bridge_channel.c: Setting 0x7fa29000b680(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2) state from:0 to:2 [Nov 9 07:07:50] DEBUG[19614][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: queueing action type:13 sub:1001 [Nov 9 07:07:50] DEBUG[19614][C-0000077a] stasis_bridges.c: Update: 0x7fa28c00c718 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:50] DEBUG[19614][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3 is dissolved, not performing smart bridge operation. [Nov 9 07:07:50] DEBUG[19614][C-0000077a] channel.c: Channel 0x7fa290006740 'PJSIP/kamailio-000000ae' hanging up. Refs: 2 [Nov 9 07:07:50] DEBUG[19614][C-0000077a] channel.c: Soft-Hanging (0x80) up channel 'PJSIP/kamailio-000000ae' [Nov 9 07:07:50] VERBOSE[19614][C-0000077a] app_stack.c: PJSIP/kamailio-000000ae Internal Gosub(api_ivr_leg1,leghangup,1) start [Nov 9 07:07:50] DEBUG[19614][C-0000077a] app_stack.c: PJSIP/kamailio-000000ae Original location: internal,,1 [Nov 9 07:07:50] DEBUG[19614][C-0000077a] app_stack.c: Gosub exited with status 0 [Nov 9 07:07:50] DEBUG[19614][C-0000077a] pbx.c: Launching 'AGI' [Nov 9 07:07:50] VERBOSE[19614][C-0000077a] pbx.c: Executing [leghangup@api_ivr_leg1:1] AGI("PJSIP/kamailio-000000ae", "agi://127.0.0.1/leghangup") in new stack [Nov 9 07:07:50] DEBUG[19614][C-0000077a] res_agi.c: Hungup channel detected, running agi in dead mode. [Nov 9 07:07:50] DEBUG[19614][C-0000077a] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 07:07:50] DEBUG[19614][C-0000077a] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 07:07:50] DEBUG[19614][C-0000077a] res_agi.c: Wow, connected! [Nov 9 07:07:50] DEBUG[19611][C-0000077a] bridge_channel.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: pulling 0x7fa29000b680(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2) [Nov 9 07:07:50] VERBOSE[19611][C-0000077a] bridge_channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 left 'simple_bridge' basic-bridge <4af0a403-5498-4541-b6f9-cb85951927a3> [Nov 9 07:07:50] DEBUG[19611][C-0000077a] bridge_channel.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: 0x7fa29000b680(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2) is leaving simple_bridge technology [Nov 9 07:07:50] DEBUG[19611][C-0000077a] stasis_bridges.c: Update: 0x7fa29001a7d8 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:50] DEBUG[19611][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3 is dissolved, not performing smart bridge operation. [Nov 9 07:07:50] DEBUG[19611][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: actually destroying basic bridge, nobody wants it anymore [Nov 9 07:07:50] DEBUG[19611][C-0000077a] stasis_bridges.c: Update: 0x7fa29000ae28 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: [Nov 9 07:07:50] DEBUG[19611][C-0000077a] stasis.c: Destroying topic. name: bridge:all/bridge:4af0a403-5498-4541-b6f9-cb85951927a3, detail: [Nov 9 07:07:50] DEBUG[19611][C-0000077a] stasis.c: Topic 'bridge:all/bridge:4af0a403-5498-4541-b6f9-cb85951927a3': 0x7fa290003f50 destroyed [Nov 9 07:07:50] DEBUG[19611][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: calling basic bridge destructor [Nov 9 07:07:50] DEBUG[19611][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: calling simple_bridge technology stop [Nov 9 07:07:50] DEBUG[19611][C-0000077a] bridge.c: Bridge 4af0a403-5498-4541-b6f9-cb85951927a3: calling simple_bridge technology destructor [Nov 9 07:07:50] DEBUG[19611][C-0000077a] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Nov 9 07:07:50] DEBUG[19611][C-0000077a] app_dial.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2: Done [Nov 9 07:07:50] DEBUG[19611][C-0000077a] pbx.c: Spawn extension (api_ivr_leg1,attempt,1) exited non-zero on 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' [Nov 9 07:07:50] VERBOSE[19611][C-0000077a] pbx.c: Spawn extension (api_ivr_leg1, attempt, 1) exited non-zero on 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' [Nov 9 07:07:50] DEBUG[19611][C-0000077a] channel.c: Soft-Hanging (0x10) up channel 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' [Nov 9 07:07:50] DEBUG[19611][C-0000077a] channel.c: Soft-Hanging (0x80) up channel 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' [Nov 9 07:07:50] VERBOSE[19611][C-0000077a] app_stack.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 Internal Gosub(api_ivr_leg1,leghangup,1) start [Nov 9 07:07:50] DEBUG[19611][C-0000077a] app_stack.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 Original location: api_ivr_leg1,attempt,1 [Nov 9 07:07:50] DEBUG[19611][C-0000077a] app_stack.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 has no datastore, so we're allocating one. [Nov 9 07:07:50] DEBUG[19611][C-0000077a] app_stack.c: Gosub exited with status 0 [Nov 9 07:07:50] DEBUG[19611][C-0000077a] pbx.c: Launching 'AGI' [Nov 9 07:07:50] VERBOSE[19611][C-0000077a] pbx.c: Executing [leghangup@api_ivr_leg1:1] AGI("Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2", "agi://127.0.0.1/leghangup") in new stack [Nov 9 07:07:50] DEBUG[19611][C-0000077a] res_agi.c: Hungup channel detected, running agi in dead mode. [Nov 9 07:07:50] DEBUG[19611][C-0000077a] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 07:07:50] DEBUG[19611][C-0000077a] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 07:07:50] DEBUG[19611][C-0000077a] res_agi.c: Wow, connected! [Nov 9 07:07:50] DEBUG[3547] stasis_bridges.c: Update: 0x7fa28c00c718 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:50] DEBUG[3547] stasis_bridges.c: Update: 0x7fa29001a7d8 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: 4af0a403-5498-4541-b6f9-cb85951927a3 [Nov 9 07:07:50] DEBUG[3547] stasis_bridges.c: Update: 0x7fa29000ae28 Old: 4af0a403-5498-4541-b6f9-cb85951927a3 New: [Nov 9 07:07:50] DEBUG[19614][C-0000077a] pbx_variables.c: Result of 'txnId' is 'bd3b52eb-1398-451b-9fb7-7fc3630493b1' [Nov 9 07:07:50] DEBUG[19614][C-0000077a] pbx_variables.c: Result of 'legId' is 'c5cc010d-baf0-4020-b34b-daea453d2655' [Nov 9 07:07:50] DEBUG[19617][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad: Indicated Media SSRC change [Nov 9 07:07:50] DEBUG[19617][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad [Nov 9 07:07:50] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'txnId' is 'bd3b52eb-1398-451b-9fb7-7fc3630493b1' [Nov 9 07:07:50] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'legId' is 'Local-api_ivr_leg1-bd3b52eb-1398-451b-9fb7-7fc3630493b1' [Nov 9 07:07:50] DEBUG[19614][C-0000077a] pbx_variables.c: Result of 'MIXMONITOR_FILENAME' is NULL [Nov 9 07:07:50] DEBUG[19611][C-0000077a] pbx_variables.c: Result of 'MIXMONITOR_FILENAME' is NULL [Nov 9 07:07:50] VERBOSE[19614][C-0000077a] res_agi.c: AGI Script agi://127.0.0.1/leghangup completed, returning 0 [Nov 9 07:07:50] DEBUG[19614][C-0000077a] pbx.c: Launching 'Return' [Nov 9 07:07:50] VERBOSE[19614][C-0000077a] pbx.c: Executing [leghangup@api_ivr_leg1:2] Return("PJSIP/kamailio-000000ae", "") in new stack [Nov 9 07:07:50] DEBUG[19614][C-0000077a] app_stack.c: Spawn extension (internal,,1) exited with -1 on 'PJSIP/kamailio-000000ae' [Nov 9 07:07:50] VERBOSE[19614][C-0000077a] app_stack.c: Spawn extension (internal, , 1) exited non-zero on 'PJSIP/kamailio-000000ae' [Nov 9 07:07:50] VERBOSE[19614][C-0000077a] app_stack.c: PJSIP/kamailio-000000ae Internal Gosub(api_ivr_leg1,leghangup,1) complete GOSUB_RETVAL= [Nov 9 07:07:50] DEBUG[19614][C-0000077a] app_stack.c: PJSIP/kamailio-000000ae Ending location: internal,,1 [Nov 9 07:07:50] DEBUG[19614][C-0000077a] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:50] DEBUG[19614][C-0000077a] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Nov 9 07:07:50] DEBUG[19614][C-0000077a] chan_pjsip.c: Cause: 0 [Nov 9 07:07:50] DEBUG[2888] chan_pjsip.c: PJSIP/kamailio-000000ae [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ae Response 0 [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) DTLS stop [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa2940355d0) ICE RTP transport deallocating [Nov 9 07:07:50] DEBUG[2888] rtp_engine.c: Destroyed RTP instance '0x7fa2940355d0' [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2888] channel.c: Channel 0x7fa290006740 'PJSIP/kamailio-000000ae' destroying [Nov 9 07:07:50] DEBUG[2888] stasis.c: Destroying topic. name: channel:1667952465.3473, detail: [Nov 9 07:07:50] DEBUG[2888] stasis.c: Topic 'channel:1667952465.3473': 0x7fa29000db50 destroyed [Nov 9 07:07:50] DEBUG[2888] channel_internal_api.c: : MultistreamFormats: (nothing) [Nov 9 07:07:50] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for PJSIP - kamailio [Nov 9 07:07:50] DEBUG[2888] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 07:07:50] DEBUG[2888] chan_pjsip.c: [Nov 9 07:07:50] DEBUG[3528] devicestate.c: Changing state for PJSIP/kamailio - state 2 (In use) [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: (null session) TSX State: Terminated Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: inv_session 0x7fa2940bd9e8 has no ast session [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The UAS CANCEL transaction involved in this state change is 0x7fa2940b4a38 [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The current transaction state is Terminated [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The transaction state change event is TIMER [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The current inv state is DISCONNCTD [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: Session ended [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: (null session) TSX State: Terminated Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: (null session) TSX State: Terminated Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: inv_session 0x7fa294073f18 has no ast session [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7fa294078958 [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The current transaction state is Terminated [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The transaction state change event is TIMER [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The current inv state is DISCONNCTD [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: Session ended [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: (null session) TSX State: Terminated Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: (null session) TSX State: Terminated Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: inv_session 0x7fa2940b6eb8 has no ast session [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The UAS CANCEL transaction involved in this state change is 0x7fa2880c3e88 [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The current transaction state is Terminated [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The transaction state change event is TIMER [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: The current inv state is DISCONNCTD [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: Session ended [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: (null session) TSX State: Terminated Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[3553] res_pjsip_session.c: [Nov 9 07:07:50] VERBOSE[19611][C-0000077a] res_agi.c: AGI Script agi://127.0.0.1/leghangup completed, returning 0 [Nov 9 07:07:50] DEBUG[19611][C-0000077a] pbx.c: Launching 'Return' [Nov 9 07:07:50] VERBOSE[19611][C-0000077a] pbx.c: Executing [leghangup@api_ivr_leg1:2] Return("Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2", "") in new stack [Nov 9 07:07:50] DEBUG[19611][C-0000077a] app_stack.c: Spawn extension (api_ivr_leg1,attempt,1) exited with -1 on 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' [Nov 9 07:07:50] VERBOSE[19611][C-0000077a] app_stack.c: Spawn extension (api_ivr_leg1, attempt, 1) exited non-zero on 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' [Nov 9 07:07:50] VERBOSE[19611][C-0000077a] app_stack.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 Internal Gosub(api_ivr_leg1,leghangup,1) complete GOSUB_RETVAL= [Nov 9 07:07:50] DEBUG[19611][C-0000077a] app_stack.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2 Ending location: api_ivr_leg1,attempt,1 [Nov 9 07:07:50] DEBUG[19611][C-0000077a] channel.c: Channel 0x7fa284018390 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' hanging up. Refs: 2 [Nov 9 07:07:50] DEBUG[19611][C-0000077a] channel.c: Channel 0x7fa284018390 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;2' destroying [Nov 9 07:07:50] DEBUG[19610][C-0000077b] bridge_channel.c: Setting 0x7fa28410cad0(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1) state from:0 to:1 [Nov 9 07:07:50] DEBUG[19611][C-0000077a] stasis.c: Destroying topic. name: channel:1667952465.3472, detail: [Nov 9 07:07:50] DEBUG[19611][C-0000077a] stasis.c: Topic 'channel:1667952465.3472': 0x7fa2840bf680 destroyed [Nov 9 07:07:50] DEBUG[19610][C-0000077b] bridge_channel.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: pulling 0x7fa28410cad0(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1) [Nov 9 07:07:50] DEBUG[19611][C-0000077a] channel_internal_api.c: : MultistreamFormats: (nothing) [Nov 9 07:07:50] DEBUG[19611][C-0000077a] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 07:07:50] VERBOSE[19610][C-0000077b] bridge_channel.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 left 'simple_bridge' basic-bridge [Nov 9 07:07:50] DEBUG[19610][C-0000077b] bridge_channel.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: 0x7fa28410cad0(Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1) is leaving simple_bridge technology [Nov 9 07:07:50] DEBUG[19610][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: dissolving bridge with cause 16(Normal Clearing) [Nov 9 07:07:50] DEBUG[19610][C-0000077b] bridge_channel.c: Setting 0x7fa28403a520(PJSIP/tssbc1_vendor-000000ad) state from:0 to:2 [Nov 9 07:07:50] DEBUG[19610][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: queueing action type:13 sub:1001 [Nov 9 07:07:50] DEBUG[19610][C-0000077b] stasis_bridges.c: Update: 0x7fa284016d18 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:50] DEBUG[19610][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204 is dissolved, not performing smart bridge operation. [Nov 9 07:07:50] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for Local - bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 [Nov 9 07:07:50] DEBUG[3528] devicestate.c: Changing state for Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 - state 1 (Not in use) [Nov 9 07:07:50] DEBUG[19610][C-0000077b] res_agi.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 hungup [Nov 9 07:07:50] DEBUG[19617][C-0000077b] bridge_channel.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: pulling 0x7fa28403a520(PJSIP/tssbc1_vendor-000000ad) [Nov 9 07:07:50] VERBOSE[19617][C-0000077b] bridge_channel.c: Channel PJSIP/tssbc1_vendor-000000ad left 'simple_bridge' basic-bridge [Nov 9 07:07:50] DEBUG[19617][C-0000077b] bridge_channel.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: 0x7fa28403a520(PJSIP/tssbc1_vendor-000000ad) is leaving simple_bridge technology [Nov 9 07:07:50] DEBUG[19617][C-0000077b] stasis_bridges.c: Update: 0x7fa298004808 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:50] DEBUG[19617][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204 is dissolved, not performing smart bridge operation. [Nov 9 07:07:50] DEBUG[19617][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad: Indicated Media SSRC change [Nov 9 07:07:50] DEBUG[19617][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad [Nov 9 07:07:50] DEBUG[19617][C-0000077b] bridge_channel.c: Bridge is returning 0x7fa28403a520(PJSIP/tssbc1_vendor-000000ad) to read format alaw [Nov 9 07:07:50] DEBUG[19617][C-0000077b] channel.c: Channel PJSIP/tssbc1_vendor-000000ad setting read format path: alaw -> alaw [Nov 9 07:07:50] DEBUG[19617][C-0000077b] bridge_channel.c: Bridge is returning 0x7fa28403a520(PJSIP/tssbc1_vendor-000000ad) to write format gsm [Nov 9 07:07:50] DEBUG[19617][C-0000077b] channel.c: Channel PJSIP/tssbc1_vendor-000000ad setting write format path: gsm -> alaw [Nov 9 07:07:50] DEBUG[19617][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: actually destroying basic bridge, nobody wants it anymore [Nov 9 07:07:50] DEBUG[19617][C-0000077b] stasis_bridges.c: Update: 0x7fa29800fd38 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: [Nov 9 07:07:50] DEBUG[19617][C-0000077b] stasis.c: Destroying topic. name: bridge:all/bridge:e8f6bad8-f952-4e77-97ad-4053441a0204, detail: [Nov 9 07:07:50] DEBUG[19617][C-0000077b] stasis.c: Topic 'bridge:all/bridge:e8f6bad8-f952-4e77-97ad-4053441a0204': 0x7fa28411d260 destroyed [Nov 9 07:07:50] DEBUG[19617][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: calling basic bridge destructor [Nov 9 07:07:50] DEBUG[19617][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: calling simple_bridge technology stop [Nov 9 07:07:50] DEBUG[19617][C-0000077b] bridge.c: Bridge e8f6bad8-f952-4e77-97ad-4053441a0204: calling simple_bridge technology destructor [Nov 9 07:07:50] DEBUG[19617][C-0000077b] channel.c: Channel 0x7fa284015010 'PJSIP/tssbc1_vendor-000000ad' hanging up. Refs: 2 [Nov 9 07:07:50] DEBUG[19617][C-0000077b] channel.c: Soft-Hanging (0x80) up channel 'PJSIP/tssbc1_vendor-000000ad' [Nov 9 07:07:50] VERBOSE[19617][C-0000077b] app_stack.c: PJSIP/tssbc1_vendor-000000ad Internal Gosub(followme,leghangup,1) start [Nov 9 07:07:50] DEBUG[19617][C-0000077b] app_stack.c: PJSIP/tssbc1_vendor-000000ad Original location: followme,onpause,2 [Nov 9 07:07:50] DEBUG[19617][C-0000077b] app_stack.c: Channel PJSIP/tssbc1_vendor-000000ad has no datastore, so we're allocating one. [Nov 9 07:07:50] DEBUG[19617][C-0000077b] app_stack.c: Gosub exited with status 0 [Nov 9 07:07:50] DEBUG[19617][C-0000077b] pbx.c: Launching 'AGI' [Nov 9 07:07:50] VERBOSE[19617][C-0000077b] pbx.c: Executing [leghangup@followme:1] AGI("PJSIP/tssbc1_vendor-000000ad", "agi://127.0.0.1/leghangup") in new stack [Nov 9 07:07:50] DEBUG[19617][C-0000077b] res_agi.c: Hungup channel detected, running agi in dead mode. [Nov 9 07:07:50] DEBUG[19617][C-0000077b] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 07:07:50] DEBUG[19617][C-0000077b] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 07:07:50] DEBUG[19617][C-0000077b] res_agi.c: Wow, connected! [Nov 9 07:07:50] DEBUG[3547] stasis_bridges.c: Update: 0x7fa284016d18 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:50] DEBUG[3547] stasis_bridges.c: Update: 0x7fa298004808 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: e8f6bad8-f952-4e77-97ad-4053441a0204 [Nov 9 07:07:50] DEBUG[3547] stasis_bridges.c: Update: 0x7fa29800fd38 Old: e8f6bad8-f952-4e77-97ad-4053441a0204 New: [Nov 9 07:07:50] VERBOSE[19610][C-0000077b] res_agi.c: AGI Script agi://127.0.0.1/dial completed, returning 4 [Nov 9 07:07:50] DEBUG[19610][C-0000077b] utils.c: write() failed due to reading end being closed: Broken pipe [Nov 9 07:07:50] DEBUG[19610][C-0000077b] pbx.c: Spawn extension (api_ivr_leg2,bd3b52eb-1398-451b-9fb7-7fc3630493b1,1) exited non-zero on 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1' [Nov 9 07:07:50] VERBOSE[19610][C-0000077b] pbx.c: Spawn extension (api_ivr_leg2, bd3b52eb-1398-451b-9fb7-7fc3630493b1, 1) exited non-zero on 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1' [Nov 9 07:07:50] DEBUG[19610][C-0000077b] channel.c: Soft-Hanging (0x10) up channel 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1' [Nov 9 07:07:50] DEBUG[19610][C-0000077b] channel.c: Soft-Hanging (0x80) up channel 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1' [Nov 9 07:07:50] VERBOSE[19610][C-0000077b] app_stack.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 Internal Gosub(api_ivr_leg2,leghangup,1) start [Nov 9 07:07:50] DEBUG[19610][C-0000077b] app_stack.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 Original location: api_ivr_leg2,bd3b52eb-1398-451b-9fb7-7fc3630493b1,1 [Nov 9 07:07:50] DEBUG[19610][C-0000077b] app_stack.c: Channel Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 has no datastore, so we're allocating one. [Nov 9 07:07:50] DEBUG[19610][C-0000077b] app_stack.c: Gosub exited with status 0 [Nov 9 07:07:50] DEBUG[19610][C-0000077b] pbx.c: Launching 'AGI' [Nov 9 07:07:50] VERBOSE[19610][C-0000077b] pbx.c: Executing [leghangup@api_ivr_leg2:1] AGI("Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1", "agi://127.0.0.1/leghangup") in new stack [Nov 9 07:07:50] DEBUG[19610][C-0000077b] res_agi.c: Hungup channel detected, running agi in dead mode. [Nov 9 07:07:50] DEBUG[19610][C-0000077b] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 07:07:50] DEBUG[19610][C-0000077b] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 07:07:50] DEBUG[19610][C-0000077b] res_agi.c: Wow, connected! [Nov 9 07:07:50] DEBUG[19617][C-0000077b] pbx_variables.c: Result of 'txnId' is 'a066de09-594b-4711-ac57-9f670f10873d' [Nov 9 07:07:50] DEBUG[19617][C-0000077b] pbx_variables.c: Result of 'legId' is '87325986-5fc2-11ed-8778-3364887a6b64' [Nov 9 07:07:50] DEBUG[19610][C-0000077b] pbx_variables.c: Result of 'txnId' is 'bd3b52eb-1398-451b-9fb7-7fc3630493b1' [Nov 9 07:07:50] DEBUG[19610][C-0000077b] pbx_variables.c: Result of 'legId' is 'Local-api_ivr_leg2-bd3b52eb-1398-451b-9fb7-7fc3630493b1' [Nov 9 07:07:50] DEBUG[19610][C-0000077b] pbx_variables.c: Result of 'MIXMONITOR_FILENAME' is NULL [Nov 9 07:07:50] DEBUG[19617][C-0000077b] pbx_variables.c: Result of 'MIXMONITOR_FILENAME' is NULL [Nov 9 07:07:50] VERBOSE[19610][C-0000077b] res_agi.c: AGI Script agi://127.0.0.1/leghangup completed, returning 0 [Nov 9 07:07:50] DEBUG[19610][C-0000077b] pbx.c: Launching 'Return' [Nov 9 07:07:50] VERBOSE[19610][C-0000077b] pbx.c: Executing [leghangup@api_ivr_leg2:2] Return("Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1", "") in new stack [Nov 9 07:07:50] DEBUG[19610][C-0000077b] app_stack.c: Spawn extension (api_ivr_leg2,bd3b52eb-1398-451b-9fb7-7fc3630493b1,1) exited with -1 on 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1' [Nov 9 07:07:50] VERBOSE[19610][C-0000077b] app_stack.c: Spawn extension (api_ivr_leg2, bd3b52eb-1398-451b-9fb7-7fc3630493b1, 1) exited non-zero on 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1' [Nov 9 07:07:50] VERBOSE[19610][C-0000077b] app_stack.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 Internal Gosub(api_ivr_leg2,leghangup,1) complete GOSUB_RETVAL= [Nov 9 07:07:50] DEBUG[19610][C-0000077b] app_stack.c: Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1 Ending location: api_ivr_leg2,bd3b52eb-1398-451b-9fb7-7fc3630493b1,1 [Nov 9 07:07:50] DEBUG[19610][C-0000077b] channel.c: Channel 0x7fa28406b610 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1' hanging up. Refs: 2 [Nov 9 07:07:50] DEBUG[19610][C-0000077b] channel.c: Channel 0x7fa28406b610 'Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1-000000ea;1' destroying [Nov 9 07:07:50] DEBUG[19610][C-0000077b] stasis.c: Destroying topic. name: channel:1667952465.3471, detail: [Nov 9 07:07:50] DEBUG[19610][C-0000077b] stasis.c: Topic 'channel:1667952465.3471': 0x7fa28406ff60 destroyed [Nov 9 07:07:50] DEBUG[19610][C-0000077b] channel_internal_api.c: : MultistreamFormats: (nothing) [Nov 9 07:07:50] DEBUG[19610][C-0000077b] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 07:07:50] NOTICE[19610][C-0000077b] pbx_spool.c: Call completed to Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 [Nov 9 07:07:50] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for Local - bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 [Nov 9 07:07:50] DEBUG[3528] core_local.c: Checking if extension bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 exists (devicestate) [Nov 9 07:07:50] DEBUG[3528] devicestate.c: Changing state for Local/bd3b52eb-1398-451b-9fb7-7fc3630493b1@api_ivr_leg1 - state 1 (Not in use) [Nov 9 07:07:50] VERBOSE[19617][C-0000077b] res_agi.c: AGI Script agi://127.0.0.1/leghangup completed, returning 0 [Nov 9 07:07:50] DEBUG[19617][C-0000077b] pbx.c: Launching 'Return' [Nov 9 07:07:50] VERBOSE[19617][C-0000077b] pbx.c: Executing [leghangup@followme:2] Return("PJSIP/tssbc1_vendor-000000ad", "") in new stack [Nov 9 07:07:50] DEBUG[19617][C-0000077b] app_stack.c: Spawn extension (followme,onpause,2) exited with -1 on 'PJSIP/tssbc1_vendor-000000ad' [Nov 9 07:07:50] VERBOSE[19617][C-0000077b] app_stack.c: Spawn extension (followme, onpause, 2) exited non-zero on 'PJSIP/tssbc1_vendor-000000ad' [Nov 9 07:07:50] VERBOSE[19617][C-0000077b] app_stack.c: PJSIP/tssbc1_vendor-000000ad Internal Gosub(followme,leghangup,1) complete GOSUB_RETVAL= [Nov 9 07:07:50] DEBUG[19617][C-0000077b] app_stack.c: PJSIP/tssbc1_vendor-000000ad Ending location: followme,onpause,2 [Nov 9 07:07:50] DEBUG[19617][C-0000077b] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad [Nov 9 07:07:50] DEBUG[19617][C-0000077b] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Nov 9 07:07:50] DEBUG[19617][C-0000077b] chan_pjsip.c: Cause: 0 [Nov 9 07:07:50] DEBUG[2131] chan_pjsip.c: PJSIP/tssbc1_vendor-000000ad [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/tssbc1_vendor-000000ad Response 0 [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa28406dfa0) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa28406dfa0) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa28406dfa0) DTLS stop [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa28406dfa0) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa28406dfa0) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa28406dfa0) ICE RTP transport deallocating [Nov 9 07:07:50] DEBUG[2131] rtp_engine.c: Destroyed RTP instance '0x7fa28406dfa0' [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/tssbc1_vendor-000000ad: Method is BYE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/tssbc1_vendor-000000ad [Nov 9 07:07:50] DEBUG[2131] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '172.21.32.116' [Nov 9 07:07:50] DEBUG[2131] res_pjsip/pjsip_resolver.c: Transport type for target '172.21.32.116' is 'UDP transport' [Nov 9 07:07:50] DEBUG[2131] res_pjsip/pjsip_resolver.c: Target '172.21.32.116' is an IP address, skipping resolution [Nov 9 07:07:50] DEBUG[2131] netsock2.c: Splitting '172.21.32.116' into... [Nov 9 07:07:50] DEBUG[2131] netsock2.c: ...host '172.21.32.116' and port ''. [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/tssbc1_vendor-000000ad TSX State: Calling Inv State: CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'tssbc1_vendor(PJSIP/tssbc1_vendor-000000ad)' [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7fa2880c3e88 [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current transaction state is Calling [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The transaction state change event is TX_MSG [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current inv state is CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/tssbc1_vendor-000000ad TSX State: Calling Inv State: CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Topology: Pending: (null topology) Active: (null topology) [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2131] channel.c: Channel 0x7fa284015010 'PJSIP/tssbc1_vendor-000000ad' destroying [Nov 9 07:07:50] DEBUG[2131] stasis.c: Destroying topic. name: channel:1667952461.3470, detail: [Nov 9 07:07:50] DEBUG[2131] stasis.c: Topic 'channel:1667952461.3470': 0x7fa2840b8e00 destroyed [Nov 9 07:07:50] DEBUG[2131] channel_internal_api.c: : MultistreamFormats: (nothing) [Nov 9 07:07:50] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for PJSIP - tssbc1_vendor [Nov 9 07:07:50] DEBUG[2131] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 07:07:50] DEBUG[2131] chan_pjsip.c: [Nov 9 07:07:50] DEBUG[3528] devicestate.c: Changing state for PJSIP/tssbc1_vendor - state 1 (Not in use) [Nov 9 07:07:50] DEBUG[3553] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7fa28c010bd8 for Response msg 200/BYE/cseq=3456 (rdata0x7fa2a0001108) [Nov 9 07:07:50] DEBUG[3553] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-00000035 associated with dialog dlg0x7fa28c010bd8 [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_vendor Method: BYE Status: 200 [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_vendor Event: TSX_STATE Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The state change pertains to the endpoint 'tssbc1_vendor()' [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The current inv state is DISCONNCTD [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_vendor: Source of transaction state change is RX_MSG [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_vendor: Received response [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_vendor: Response is 200 OK [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_vendor [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_vendor TSX State: Completed Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The state change pertains to the endpoint 'tssbc1_vendor()' [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7fa2880c3e88 [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The current transaction state is Completed [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The transaction state change event is RX_MSG [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The current inv state is DISCONNCTD [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_vendor: Response is 200 OK [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_vendor [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_vendor: BYE received final response code 200 [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_vendor TSX State: Completed Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: Topology: Pending: (null topology) Active: (null topology) [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2888] chan_pjsip.c: tssbc1_vendor [Nov 9 07:07:50] DEBUG[2888] chan_pjsip.c: No channel [Nov 9 07:07:50] DEBUG[3553] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7fa288010028 for Request msg BYE/cseq=59422443 (rdata0x7fa2a0001108) [Nov 9 07:07:50] DEBUG[3553] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/kamailio-0000061f associated with dialog dlg0x7fa288010028 [Nov 9 07:07:50] DEBUG[2131] netsock2.c: Splitting '172.21.144.120' into... [Nov 9 07:07:50] DEBUG[2131] netsock2.c: ...host '172.21.144.120' and port ''. [Nov 9 07:07:50] DEBUG[2131] res_pjsip_nat.c: Request is being sent to local address, skipping NAT manipulation [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ac TSX State: Completed Inv State: CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ac)' [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x2124738 [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current transaction state is Completed [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The transaction state change event is TX_MSG [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current inv state is CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ac TSX State: Completed Inv State: CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ac Event: TSX_STATE Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ac)' [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current inv state is DISCONNCTD [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ac: Source of transaction state change is RX_MSG [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ac: Received request [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ac: Method is BYE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ac [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ac TSX State: Completed Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-000000ac)' [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The UAS BYE transaction involved in this state change is 0x2124738 [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current transaction state is Completed [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The transaction state change event is RX_MSG [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current inv state is DISCONNCTD [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/kamailio-000000ac TSX State: Completed Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2131] chan_pjsip.c: PJSIP/kamailio-000000ac [Nov 9 07:07:50] DEBUG[2131] chan_pjsip.c: [Nov 9 07:07:50] DEBUG[19608][C-00000778] bridge_channel.c: Setting 0x7fa2b800d310(PJSIP/kamailio-000000ac) state from:0 to:1 [Nov 9 07:07:50] DEBUG[19608][C-00000778] bridge_channel.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6: pulling 0x7fa2b800d310(PJSIP/kamailio-000000ac) [Nov 9 07:07:50] VERBOSE[19608][C-00000778] bridge_channel.c: Channel PJSIP/kamailio-000000ac left 'simple_bridge' basic-bridge [Nov 9 07:07:50] DEBUG[19608][C-00000778] bridge_channel.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6: 0x7fa2b800d310(PJSIP/kamailio-000000ac) is leaving simple_bridge technology [Nov 9 07:07:50] DEBUG[19608][C-00000778] bridge.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6: dissolving bridge with cause 16(Normal Clearing) [Nov 9 07:07:50] DEBUG[19608][C-00000778] bridge_channel.c: Setting 0x7fa2b8016d10(PJSIP/tssbc1_registrar-000000ab) state from:0 to:2 [Nov 9 07:07:50] DEBUG[19608][C-00000778] bridge.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6: queueing action type:13 sub:1001 [Nov 9 07:07:50] DEBUG[19608][C-00000778] stasis_bridges.c: Update: 0x7fa288003f28 Old: c7fd60f7-37b4-4c80-8d31-8645c867dfd6 New: c7fd60f7-37b4-4c80-8d31-8645c867dfd6 [Nov 9 07:07:50] DEBUG[19608][C-00000778] bridge.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6 is dissolved, not performing smart bridge operation. [Nov 9 07:07:50] DEBUG[3547] stasis_bridges.c: Update: 0x7fa288003f28 Old: c7fd60f7-37b4-4c80-8d31-8645c867dfd6 New: c7fd60f7-37b4-4c80-8d31-8645c867dfd6 [Nov 9 07:07:50] DEBUG[19608][C-00000778] channel.c: Channel 0x7fa2b8012080 'PJSIP/kamailio-000000ac' hanging up. Refs: 2 [Nov 9 07:07:50] DEBUG[19608][C-00000778] channel.c: Soft-Hanging (0x80) up channel 'PJSIP/kamailio-000000ac' [Nov 9 07:07:50] VERBOSE[19608][C-00000778] app_stack.c: PJSIP/kamailio-000000ac Internal Gosub(sip_pstn,leghangup,1) start [Nov 9 07:07:50] DEBUG[19608][C-00000778] app_stack.c: PJSIP/kamailio-000000ac Original location: internal,,1 [Nov 9 07:07:50] DEBUG[19593][C-00000778] bridge_channel.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6: pulling 0x7fa2b8016d10(PJSIP/tssbc1_registrar-000000ab) [Nov 9 07:07:50] VERBOSE[19593][C-00000778] bridge_channel.c: Channel PJSIP/tssbc1_registrar-000000ab left 'simple_bridge' basic-bridge [Nov 9 07:07:50] DEBUG[19593][C-00000778] bridge_channel.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6: 0x7fa2b8016d10(PJSIP/tssbc1_registrar-000000ab) is leaving simple_bridge technology [Nov 9 07:07:50] DEBUG[19593][C-00000778] stasis_bridges.c: Update: 0x7fa2b800b678 Old: c7fd60f7-37b4-4c80-8d31-8645c867dfd6 New: c7fd60f7-37b4-4c80-8d31-8645c867dfd6 [Nov 9 07:07:50] DEBUG[19608][C-00000778] app_stack.c: Gosub exited with status 0 [Nov 9 07:07:50] DEBUG[19593][C-00000778] bridge.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6 is dissolved, not performing smart bridge operation. [Nov 9 07:07:50] DEBUG[19608][C-00000778] pbx.c: Launching 'AGI' [Nov 9 07:07:50] VERBOSE[19608][C-00000778] pbx.c: Executing [leghangup@sip_pstn:1] AGI("PJSIP/kamailio-000000ac", "agi://127.0.0.1/leghangup") in new stack [Nov 9 07:07:50] DEBUG[19593][C-00000778] chan_pjsip.c: PJSIP/tssbc1_registrar-000000ab: Indicated Media SSRC change [Nov 9 07:07:50] DEBUG[19593][C-00000778] chan_pjsip.c: PJSIP/tssbc1_registrar-000000ab [Nov 9 07:07:50] DEBUG[19608][C-00000778] res_agi.c: Hungup channel detected, running agi in dead mode. [Nov 9 07:07:50] DEBUG[19608][C-00000778] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 07:07:50] DEBUG[19608][C-00000778] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 07:07:50] DEBUG[19593][C-00000778] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Nov 9 07:07:50] DEBUG[19593][C-00000778] app_dial.c: PJSIP/tssbc1_registrar-000000ab: Done [Nov 9 07:07:50] DEBUG[19593][C-00000778] pbx.c: Spawn extension (sip_pstn,attempt,1) exited non-zero on 'PJSIP/tssbc1_registrar-000000ab' [Nov 9 07:07:50] VERBOSE[19593][C-00000778] pbx.c: Spawn extension (sip_pstn, attempt, 1) exited non-zero on 'PJSIP/tssbc1_registrar-000000ab' [Nov 9 07:07:50] DEBUG[19593][C-00000778] channel.c: Soft-Hanging (0x10) up channel 'PJSIP/tssbc1_registrar-000000ab' [Nov 9 07:07:50] DEBUG[19593][C-00000778] channel.c: Soft-Hanging (0x80) up channel 'PJSIP/tssbc1_registrar-000000ab' [Nov 9 07:07:50] VERBOSE[19593][C-00000778] app_stack.c: PJSIP/tssbc1_registrar-000000ab Internal Gosub(sip_pstn,leghangup,1) start [Nov 9 07:07:50] DEBUG[19593][C-00000778] app_stack.c: PJSIP/tssbc1_registrar-000000ab Original location: sip_pstn,attempt,1 [Nov 9 07:07:50] DEBUG[19593][C-00000778] app_stack.c: Channel PJSIP/tssbc1_registrar-000000ab has no datastore, so we're allocating one. [Nov 9 07:07:50] DEBUG[19593][C-00000778] app_stack.c: Gosub exited with status 0 [Nov 9 07:07:50] DEBUG[19608][C-00000778] res_agi.c: Wow, connected! [Nov 9 07:07:50] DEBUG[19593][C-00000778] pbx.c: Launching 'AGI' [Nov 9 07:07:50] VERBOSE[19593][C-00000778] pbx.c: Executing [leghangup@sip_pstn:1] AGI("PJSIP/tssbc1_registrar-000000ab", "agi://127.0.0.1/leghangup") in new stack [Nov 9 07:07:50] DEBUG[19593][C-00000778] res_agi.c: Hungup channel detected, running agi in dead mode. [Nov 9 07:07:50] DEBUG[19593][C-00000778] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 07:07:50] DEBUG[19593][C-00000778] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 07:07:50] DEBUG[19593][C-00000778] res_agi.c: Wow, connected! [Nov 9 07:07:50] DEBUG[3527][C-00000778] bridge.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6: actually destroying basic bridge, nobody wants it anymore [Nov 9 07:07:50] DEBUG[3527][C-00000778] stasis_bridges.c: Update: 0x7fa284121b78 Old: c7fd60f7-37b4-4c80-8d31-8645c867dfd6 New: [Nov 9 07:07:50] DEBUG[3527][C-00000778] stasis.c: Destroying topic. name: bridge:all/bridge:c7fd60f7-37b4-4c80-8d31-8645c867dfd6, detail: [Nov 9 07:07:50] DEBUG[3527][C-00000778] stasis.c: Topic 'bridge:all/bridge:c7fd60f7-37b4-4c80-8d31-8645c867dfd6': 0x7fa2b8019150 destroyed [Nov 9 07:07:50] DEBUG[3527][C-00000778] bridge.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6: calling basic bridge destructor [Nov 9 07:07:50] DEBUG[3527][C-00000778] bridge.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6: calling simple_bridge technology stop [Nov 9 07:07:50] DEBUG[3527][C-00000778] bridge.c: Bridge c7fd60f7-37b4-4c80-8d31-8645c867dfd6: calling simple_bridge technology destructor [Nov 9 07:07:50] DEBUG[3547] stasis_bridges.c: Update: 0x7fa2b800b678 Old: c7fd60f7-37b4-4c80-8d31-8645c867dfd6 New: c7fd60f7-37b4-4c80-8d31-8645c867dfd6 [Nov 9 07:07:50] DEBUG[3547] stasis_bridges.c: Update: 0x7fa284121b78 Old: c7fd60f7-37b4-4c80-8d31-8645c867dfd6 New: [Nov 9 07:07:50] DEBUG[19608][C-00000778] pbx_variables.c: Result of 'txnId' is 'cdba4ace-b5b5-47b2-8c2e-9442a5db31f8' [Nov 9 07:07:50] DEBUG[19608][C-00000778] pbx_variables.c: Result of 'legId' is '7cd453fb-1e72-46f4-a87d-fa34273809f5' [Nov 9 07:07:50] DEBUG[19593][C-00000778] pbx_variables.c: Result of 'txnId' is 'cdba4ace-b5b5-47b2-8c2e-9442a5db31f8' [Nov 9 07:07:50] DEBUG[19593][C-00000778] pbx_variables.c: Result of 'legId' is '86fcf1a6-5fc2-11ed-873d-3364887a6b64' [Nov 9 07:07:50] DEBUG[19608][C-00000778] pbx_variables.c: Result of 'MIXMONITOR_FILENAME' is NULL [Nov 9 07:07:50] DEBUG[19593][C-00000778] pbx_variables.c: Result of 'MIXMONITOR_FILENAME' is NULL [Nov 9 07:07:50] VERBOSE[19608][C-00000778] res_agi.c: AGI Script agi://127.0.0.1/leghangup completed, returning 0 [Nov 9 07:07:50] DEBUG[19608][C-00000778] pbx.c: Launching 'Return' [Nov 9 07:07:50] VERBOSE[19608][C-00000778] pbx.c: Executing [leghangup@sip_pstn:2] Return("PJSIP/kamailio-000000ac", "") in new stack [Nov 9 07:07:50] DEBUG[19608][C-00000778] app_stack.c: Spawn extension (internal,,1) exited with -1 on 'PJSIP/kamailio-000000ac' [Nov 9 07:07:50] VERBOSE[19608][C-00000778] app_stack.c: Spawn extension (internal, , 1) exited non-zero on 'PJSIP/kamailio-000000ac' [Nov 9 07:07:50] VERBOSE[19608][C-00000778] app_stack.c: PJSIP/kamailio-000000ac Internal Gosub(sip_pstn,leghangup,1) complete GOSUB_RETVAL= [Nov 9 07:07:50] DEBUG[19608][C-00000778] app_stack.c: PJSIP/kamailio-000000ac Ending location: internal,,1 [Nov 9 07:07:50] DEBUG[19608][C-00000778] chan_pjsip.c: PJSIP/kamailio-000000ac [Nov 9 07:07:50] DEBUG[19608][C-00000778] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Nov 9 07:07:50] DEBUG[19608][C-00000778] chan_pjsip.c: Cause: 0 [Nov 9 07:07:50] DEBUG[2888] chan_pjsip.c: PJSIP/kamailio-000000ac [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: PJSIP/kamailio-000000ac Response 0 [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa294076870) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa294076870) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa294076870) DTLS stop [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa294076870) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa294076870) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2888] res_rtp_asterisk.c: (0x7fa294076870) ICE RTP transport deallocating [Nov 9 07:07:50] DEBUG[2888] rtp_engine.c: Destroyed RTP instance '0x7fa294076870' [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2888] channel.c: Channel 0x7fa2b8012080 'PJSIP/kamailio-000000ac' destroying [Nov 9 07:07:50] DEBUG[2888] stasis.c: Destroying topic. name: channel:1667952461.3469, detail: [Nov 9 07:07:50] DEBUG[2888] stasis.c: Topic 'channel:1667952461.3469': 0x7fa2b80144e0 destroyed [Nov 9 07:07:50] DEBUG[2888] channel_internal_api.c: : MultistreamFormats: (nothing) [Nov 9 07:07:50] DEBUG[2888] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 07:07:50] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for PJSIP - kamailio [Nov 9 07:07:50] DEBUG[2888] chan_pjsip.c: [Nov 9 07:07:50] DEBUG[3528] devicestate.c: Changing state for PJSIP/kamailio - state 1 (Not in use) [Nov 9 07:07:50] VERBOSE[19593][C-00000778] res_agi.c: AGI Script agi://127.0.0.1/leghangup completed, returning 0 [Nov 9 07:07:50] DEBUG[19593][C-00000778] pbx.c: Launching 'Return' [Nov 9 07:07:50] VERBOSE[19593][C-00000778] pbx.c: Executing [leghangup@sip_pstn:2] Return("PJSIP/tssbc1_registrar-000000ab", "") in new stack [Nov 9 07:07:50] DEBUG[19593][C-00000778] app_stack.c: Spawn extension (sip_pstn,attempt,1) exited with -1 on 'PJSIP/tssbc1_registrar-000000ab' [Nov 9 07:07:50] VERBOSE[19593][C-00000778] app_stack.c: Spawn extension (sip_pstn, attempt, 1) exited non-zero on 'PJSIP/tssbc1_registrar-000000ab' [Nov 9 07:07:50] VERBOSE[19593][C-00000778] app_stack.c: PJSIP/tssbc1_registrar-000000ab Internal Gosub(sip_pstn,leghangup,1) complete GOSUB_RETVAL= [Nov 9 07:07:50] DEBUG[19593][C-00000778] app_stack.c: PJSIP/tssbc1_registrar-000000ab Ending location: sip_pstn,attempt,1 [Nov 9 07:07:50] DEBUG[19593][C-00000778] channel.c: Channel 0x7fa28405c220 'PJSIP/tssbc1_registrar-000000ab' hanging up. Refs: 2 [Nov 9 07:07:50] DEBUG[19593][C-00000778] chan_pjsip.c: PJSIP/tssbc1_registrar-000000ab [Nov 9 07:07:50] DEBUG[19593][C-00000778] chan_pjsip.c: AST hangup cause 16 (no match found in PJSIP) [Nov 9 07:07:50] DEBUG[19593][C-00000778] chan_pjsip.c: Cause: 0 [Nov 9 07:07:50] DEBUG[2131] chan_pjsip.c: PJSIP/tssbc1_registrar-000000ab [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/tssbc1_registrar-000000ab Response 0 [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa284072610) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa284072610) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa284072610) DTLS stop [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa284072610) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa284072610) DTLS srtp - stopped timeout timer' [Nov 9 07:07:50] DEBUG[2131] res_rtp_asterisk.c: (0x7fa284072610) ICE RTP transport deallocating [Nov 9 07:07:50] DEBUG[2131] rtp_engine.c: Destroyed RTP instance '0x7fa284072610' [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/tssbc1_registrar-000000ab: Method is BYE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/tssbc1_registrar-000000ab [Nov 9 07:07:50] DEBUG[2131] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '172.21.32.116' [Nov 9 07:07:50] DEBUG[2131] res_pjsip/pjsip_resolver.c: Transport type for target '172.21.32.116' is 'UDP transport' [Nov 9 07:07:50] DEBUG[2131] res_pjsip/pjsip_resolver.c: Target '172.21.32.116' is an IP address, skipping resolution [Nov 9 07:07:50] DEBUG[2131] netsock2.c: Splitting '172.21.32.116' into... [Nov 9 07:07:50] DEBUG[2131] netsock2.c: ...host '172.21.32.116' and port ''. [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/tssbc1_registrar-000000ab TSX State: Calling Inv State: CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The state change pertains to the endpoint 'tssbc1_registrar(PJSIP/tssbc1_registrar-000000ab)' [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7fa294078958 [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current transaction state is Calling [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The transaction state change event is TX_MSG [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: The current inv state is CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: PJSIP/tssbc1_registrar-000000ab TSX State: Calling Inv State: CONFIRMED [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: Topology: Pending: (null topology) Active: (null topology) [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2131] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2131] channel.c: Channel 0x7fa28405c220 'PJSIP/tssbc1_registrar-000000ab' destroying [Nov 9 07:07:50] DEBUG[2131] stasis.c: Destroying topic. name: channel:1667952461.3468, detail: [Nov 9 07:07:50] DEBUG[2131] stasis.c: Topic 'channel:1667952461.3468': 0x7fa28407d2c0 destroyed [Nov 9 07:07:50] DEBUG[2131] channel_internal_api.c: : MultistreamFormats: (nothing) [Nov 9 07:07:50] DEBUG[2131] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 07:07:50] DEBUG[2131] chan_pjsip.c: [Nov 9 07:07:50] DEBUG[3528] devicestate.c: No provider found, checking channel drivers for PJSIP - tssbc1_registrar [Nov 9 07:07:50] DEBUG[3528] devicestate.c: Changing state for PJSIP/tssbc1_registrar - state 1 (Not in use) [Nov 9 07:07:50] DEBUG[3553] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7fa2940c23e8 for Response msg 200/BYE/cseq=28580 (rdata0x7fa2a0001108) [Nov 9 07:07:50] DEBUG[3553] res_pjsip/pjsip_distributor.c: Found serializer pjsip/distributor-0000003f associated with dialog dlg0x7fa2940c23e8 [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_registrar Method: BYE Status: 200 [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_registrar Event: TSX_STATE Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The state change pertains to the endpoint 'tssbc1_registrar()' [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The current inv state is DISCONNCTD [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_registrar: Source of transaction state change is RX_MSG [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_registrar: Received response [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_registrar: Response is 200 OK [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_registrar [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_registrar TSX State: Completed Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The state change pertains to the endpoint 'tssbc1_registrar()' [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The UAC BYE transaction involved in this state change is 0x7fa294078958 [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The current transaction state is Completed [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The transaction state change event is RX_MSG [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: The current inv state is DISCONNCTD [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_registrar: Response is 200 OK [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_registrar [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_registrar: BYE received final response code 200 [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: Nothing delayed [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: tssbc1_registrar TSX State: Completed Inv State: DISCONNCTD [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: Topology: Pending: (null topology) Active: (null topology) [Nov 9 07:07:50] DEBUG[2888] res_pjsip_session.c: [Nov 9 07:07:50] DEBUG[2888] chan_pjsip.c: tssbc1_registrar [Nov 9 07:07:50] DEBUG[2888] chan_pjsip.c: No channel