[Nov 9 09:50:00] DEBUG[2981] pbx_spool.c: Filename: /var/spool/asterisk/outgoing/apicall.b6dcafa4-1587-4514-8eca-11d984752ac9, Retries: 0, max: 0 [Nov 9 09:50:00] DEBUG[2981] pbx_spool.c: Outgoing Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1: StartRetry [Nov 9 09:50:00] VERBOSE[7446] pbx_spool.c: Attempting call on Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 for b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg2:1 (Retry 1) [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: : Formats: (none) [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 09:50:00] DEBUG[7446] stasis.c: Creating topic. name: channel:1667962200.382, detail: [Nov 9 09:50:00] DEBUG[7446] stasis.c: Topic 'channel:1667962200.382': 0x7f8eb0010f40 created [Nov 9 09:50:00] DEBUG[7446] channel.c: Channel 0x7f8eb0016760 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1' allocated [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1: MultistreamFormats: (slin) [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: Set native formats but not topology [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1: <0:audio-0:audio:sendrecv (slin)> [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: Used provided topology [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: : Formats: (none) [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 09:50:00] DEBUG[7446] stasis.c: Creating topic. name: channel:1667962200.383, detail: [Nov 9 09:50:00] DEBUG[7446] stasis.c: Topic 'channel:1667962200.383': 0x7f8eb000a580 created [Nov 9 09:50:00] DEBUG[7446] channel.c: Channel 0x7f8eb000d0e0 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' allocated [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2: MultistreamFormats: (slin) [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: Set native formats but not topology [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2: <0:audio-0:audio:sendrecv (slin)> [Nov 9 09:50:00] DEBUG[7446] channel_internal_api.c: Used provided topology [Nov 9 09:50:00] VERBOSE[7446] dial.c: Called b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx.c: Launching 'AGI' [Nov 9 09:50:00] VERBOSE[7447][C-000000db] pbx.c: Executing [b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1:1] AGI("Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2", "agi://127.0.0.1/dial") in new stack [Nov 9 09:50:00] DEBUG[7447][C-000000db] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 09:50:00] DEBUG[7447][C-000000db] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 09:50:00] DEBUG[7447][C-000000db] res_agi.c: Wow, connected! [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'txnId' is 'b6dcafa4-1587-4514-8eca-11d984752ac9' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'CHANNEL' is 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' [Nov 9 09:50:00] DEBUG[7447][C-000000db] app_stack.c: Gosub args:api_ivr_leg1,leghangup,1 new_args:api_ivr_leg1,leghangup,1 [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'txnId' is 'b6dcafa4-1587-4514-8eca-11d984752ac9' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'CONTEXT' is 'api_ivr_leg1' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'container_uuid' is 'f1b40993-c8b0-49ca-a808-8d287b0e60e1' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'ringback_music' is NULL [Nov 9 09:50:00] VERBOSE[7447][C-000000db] res_agi.c: AGI Script Executing Application: (GOTO) Options: (attempt,1) [Nov 9 09:50:00] VERBOSE[7447][C-000000db] pbx_builtins.c: Goto (api_ivr_leg1,attempt,1) [Nov 9 09:50:00] VERBOSE[7447][C-000000db] res_agi.c: AGI Script agi://127.0.0.1/dial completed, returning 0 [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'dialStr' is 'PJSIP/outgoing@kamailio' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'ringtime' is '20' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Expression result is '1' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'ringtime' is '20' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Function IF(1?20:) result is '20' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'dialOpt' is 'it' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Expression result is '1' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'dialOpt' is 'it' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Function IF(1?it:) result is 'it' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'CONTEXT' is 'api_ivr_leg1' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx.c: Launching 'Dial' [Nov 9 09:50:00] VERBOSE[7447][C-000000db] pbx.c: Executing [attempt@api_ivr_leg1:1] Dial("Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2", "PJSIP/outgoing@kamailio,20,itb(api_ivr_leg1^callee_handler^1)") in new stack [Nov 9 09:50:00] DEBUG[7447][C-000000db] app_dial.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2: Data: PJSIP/outgoing@kamailio,20,itb(api_ivr_leg1^callee_handler^1) [Nov 9 09:50:00] DEBUG[7447][C-000000db] chan_pjsip.c: outgoing@kamailio Topology: <0:audio-0:audio:sendrecv (slin)> [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: outgoing@kamailio [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: kamailio outgoing Topology: <0:audio-0:audio:sendrecv (slin)> [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: kamailio [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: Direct media no glare mitigation [Nov 9 09:50:00] DEBUG[20530] 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 09:50:00] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: [Nov 9 09:50:00] DEBUG[7447][C-000000db] chan_pjsip.c: kamailio [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel_internal_api.c: : Formats: (none) [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 09:50:00] DEBUG[7447][C-000000db] stasis.c: Creating topic. name: channel:1667962200.384, detail: [Nov 9 09:50:00] DEBUG[7447][C-000000db] stasis.c: Topic 'channel:1667962200.384': 0x7f8ea80a55f0 created [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel.c: Channel 0x7f8ea8049ea0 'PJSIP/kamailio-00000143' allocated [Nov 9 09:50:00] DEBUG[2910] threadpool.c: Increasing threadpool stasis/pool's size by 1 [Nov 9 09:50:00] DEBUG[7447][C-000000db] chan_pjsip.c: Topology: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> Formats: (alaw|opus|ulaw|g729|gsm) [Nov 9 09:50:00] DEBUG[7447][C-000000db] chan_pjsip.c: Compatible? yes [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel_internal_api.c: PJSIP/kamailio-00000143: MultistreamFormats: (alaw|opus|ulaw|g729|gsm) [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel_internal_api.c: Set native formats but not topology [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel_internal_api.c: PJSIP/kamailio-00000143: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel_internal_api.c: Used provided topology [Nov 9 09:50:00] DEBUG[7447][C-000000db] chan_pjsip.c: [Nov 9 09:50:00] DEBUG[7447][C-000000db] chan_pjsip.c: Channel: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[7447][C-000000db] rtp_engine.c: Can't find native functions for channel 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel.c: Inheriting variable dstLegId from Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 to PJSIP/kamailio-00000143. [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel.c: Inheriting variable __container_uuid from Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 to PJSIP/kamailio-00000143. [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel.c: Inheriting variable __txnId from Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 to PJSIP/kamailio-00000143. [Nov 9 09:50:00] DEBUG[7447][C-000000db] app_stack.c: Gosub args:api_ivr_leg1,callee_handler,1 new_args:api_ivr_leg1,callee_handler,1 [Nov 9 09:50:00] VERBOSE[7447][C-000000db] app_stack.c: PJSIP/kamailio-00000143 Internal Gosub(api_ivr_leg1,callee_handler,1) start [Nov 9 09:50:00] DEBUG[7447][C-000000db] app_stack.c: PJSIP/kamailio-00000143 Original location: internal,attempt,1 [Nov 9 09:50:00] DEBUG[7447][C-000000db] app_stack.c: Channel PJSIP/kamailio-00000143 has no datastore, so we're allocating one. [Nov 9 09:50:00] DEBUG[7447][C-000000db] app_stack.c: Gosub exited with status 0 [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx.c: Launching 'AGI' [Nov 9 09:50:00] VERBOSE[7447][C-000000db] pbx.c: Executing [callee_handler@api_ivr_leg1:1] AGI("PJSIP/kamailio-00000143", "agi://127.0.0.1/callee_predial") in new stack [Nov 9 09:50:00] DEBUG[7447][C-000000db] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 09:50:00] DEBUG[7447][C-000000db] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 09:50:00] DEBUG[7447][C-000000db] res_agi.c: Wow, connected! [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'dstLegId' is '70d180ae-1c90-4f01-9a3c-6d21747ea694' [Nov 9 09:50:00] DEBUG[7447][C-000000db] app_stack.c: Gosub args:api_ivr_leg1,leghangup,1 new_args:api_ivr_leg1,leghangup,1 [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'txnId' is 'b6dcafa4-1587-4514-8eca-11d984752ac9' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'CHANNEL' is 'PJSIP/kamailio-00000143' [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'container_uuid' is 'f1b40993-c8b0-49ca-a808-8d287b0e60e1' [Nov 9 09:50:00] ERROR[20530] res_pjsip_header_funcs.c: No headers had been previously added to this session. [Nov 9 09:50:00] DEBUG[20530] res_pjsip_header_funcs.c: Adding header X-header-TxnId with value b6dcafa4-1587-4514-8eca-11d984752ac9 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_header_funcs.c: Adding header X-header-LegId with value 70d180ae-1c90-4f01-9a3c-6d21747ea694 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_header_funcs.c: Adding header X-header-FOLLOWME with value sip [Nov 9 09:50:00] DEBUG[20530] res_pjsip_header_funcs.c: Adding header X-header-RPEER with value sip3227456 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_header_funcs.c: Adding header X-header-SERVER-PORT with value 5060 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_header_funcs.c: Adding header X-header-DOMAIN with value siptest.b3networks.com [Nov 9 09:50:00] DEBUG[20530] res_pjsip_header_funcs.c: Adding header X-header-Vendor with value SIPTESTB3 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_header_funcs.c: Adding header X-header-R_DNIS with value 84868663741 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_header_funcs.c: Adding header X-header-R_CLID with value +84868663741 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_header_funcs.c: Adding header X-header-R_CLINAME with value 84868663741 [Nov 9 09:50:00] DEBUG[7447][C-000000db] config.c: extract int from [10] in [-2147483648, 2147483647] gives [10](0) [Nov 9 09:50:00] VERBOSE[7447][C-000000db] res_agi.c: AGI Script agi://127.0.0.1/callee_predial completed, returning 0 [Nov 9 09:50:00] DEBUG[7447][C-000000db] pbx.c: Launching 'Return' [Nov 9 09:50:00] VERBOSE[7447][C-000000db] pbx.c: Executing [callee_handler@api_ivr_leg1:2] Return("PJSIP/kamailio-00000143", "") in new stack [Nov 9 09:50:00] DEBUG[7447][C-000000db] app_stack.c: Spawn extension (internal,attempt,1) exited with -1 on 'PJSIP/kamailio-00000143' [Nov 9 09:50:00] VERBOSE[7447][C-000000db] app_stack.c: Spawn extension (internal, attempt, 1) exited non-zero on 'PJSIP/kamailio-00000143' [Nov 9 09:50:00] VERBOSE[7447][C-000000db] app_stack.c: PJSIP/kamailio-00000143 Internal Gosub(api_ivr_leg1,callee_handler,1) complete GOSUB_RETVAL= [Nov 9 09:50:00] DEBUG[7447][C-000000db] app_stack.c: PJSIP/kamailio-00000143 Ending location: internal,attempt,1 [Nov 9 09:50:00] DEBUG[7447][C-000000db] chan_pjsip.c: PJSIP/kamailio-00000143 Topology: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> [Nov 9 09:50:00] DEBUG[7447][C-000000db] chan_pjsip.c: 'call' task pushed [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143 Topology: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Processing streams [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Processing stream 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 Adding position 0 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Creating new media session [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Setting media session as default for audio [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Done [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 Stream: 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_sdp_rtp.c: PJSIP/kamailio-00000143 Type: audio 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) [Nov 9 09:50:00] DEBUG[20530] rtp_engine.c: Using engine 'asterisk' for RTP instance '0x7f8ea80212f0' [Nov 9 09:50:00] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80212f0) RTP allocated port 27146 [Nov 9 09:50:00] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80212f0) ICE creating session [::]:27146 (27146) [Nov 9 09:50:00] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80212f0) ICE create [Nov 9 09:50:00] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80212f0) ICE add system candidates [Nov 9 09:50:00] DEBUG[20530] netsock2.c: Splitting '172.21.16.66' into... [Nov 9 09:50:00] DEBUG[20530] netsock2.c: ...host '172.21.16.66' and port ''. [Nov 9 09:50:00] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80212f0) ICE add candidate: 172.21.16.66:27146, 2130706431 [Nov 9 09:50:00] DEBUG[20530] netsock2.c: Splitting 'fe80::4fc:8fff:fe94:4e4a' into... [Nov 9 09:50:00] DEBUG[20530] netsock2.c: ...host 'fe80::4fc:8fff:fe94:4e4a' and port ''. [Nov 9 09:50:00] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80212f0) ICE add candidate: [fe80::4fc:8fff:fe94:4e4a]:27146, 2130706431 [Nov 9 09:50:00] DEBUG[20530] rtp_engine.c: RTP instance '0x7f8ea80212f0' is setup and ready to go [Nov 9 09:50:00] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80212f0) ICE stopped [Nov 9 09:50:00] DEBUG[20530] netsock2.c: Splitting 'tsworker2' into... [Nov 9 09:50:00] DEBUG[20530] netsock2.c: ...host 'tsworker2' and port ''. [Nov 9 09:50:00] VERBOSE[7447][C-000000db] app_dial.c: Called PJSIP/outgoing@kamailio [Nov 9 09:50:00] DEBUG[7447][C-000000db] app_dial.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel.c: Channel PJSIP/kamailio-00000143 setting read format path: alaw -> slin [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 setting write format path: slin -> slin [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 setting read format path: slin -> slin [Nov 9 09:50:00] DEBUG[7447][C-000000db] channel.c: Channel PJSIP/kamailio-00000143 setting write format path: slin -> alaw [Nov 9 09:50:00] DEBUG[20530] acl.c: Multiple addresses. Using the first only [Nov 9 09:50:00] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80212f0) RTCP setup on RTP instance [Nov 9 09:50:00] DEBUG[20530] res_pjsip_sdp_rtp.c: RC: 1 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Handled [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Stream 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) added [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Done with 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Adding bundle groups (if available) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Copying connection details [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Processing media 0 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Media 0 reset [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Method is INVITE [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[20530] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '172.21.16.66' [Nov 9 09:50:00] DEBUG[20530] res_pjsip/pjsip_resolver.c: Transport type for target '172.21.16.66' is 'UDP transport' [Nov 9 09:50:00] DEBUG[20530] res_pjsip/pjsip_resolver.c: Target '172.21.16.66' is an IP address, skipping resolution [Nov 9 09:50:00] DEBUG[20530] res_pjsip/pjsip_message_filter.c: Re-wrote Contact URI host/port to 172.21.16.66:5060 (this may be re-written again later) [Nov 9 09:50:00] DEBUG[20530] netsock2.c: Splitting '172.21.16.66' into... [Nov 9 09:50:00] DEBUG[20530] netsock2.c: ...host '172.21.16.66' and port ''. [Nov 9 09:50:00] DEBUG[20530] res_pjsip_nat.c: Request is being sent to local address, skipping NAT manipulation [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 Event: TSX_STATE Inv State: CALLING [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-00000143)' [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8ea804c8f8) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The current inv state is CALLING [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Source of transaction state change is TX_MSG [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 TSX State: Calling Inv State: CALLING [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-00000143)' [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8ea804c8f8) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f8ea804c8f8 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The current transaction state is Calling [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The transaction state change event is TX_MSG [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The current inv state is CALLING [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Nothing delayed [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 TSX State: Calling Inv State: CALLING [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Topology: Pending: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> Active: (null topology) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: RC: 0 [Nov 9 09:50:00] DEBUG[2947] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f8ea815cda8 for Response msg 100/INVITE/cseq=29486 (rdata0x7f8e98001568) [Nov 9 09:50:00] DEBUG[2947] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/kamailio-000000f1 associated with dialog dlg0x7f8ea815cda8 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 Method: INVITE Status: 100 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 TSX State: Proceeding Inv State: CALLING [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-00000143)' [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8ea804c8f8) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f8ea804c8f8 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The current transaction state is Proceeding [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The transaction state change event is RX_MSG [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The current inv state is CALLING [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Response is 100 Trying [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143: Status: 100 [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143: Not queueing anything [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143: Status: 100 [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Nothing delayed [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 TSX State: Proceeding Inv State: CALLING [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Topology: Pending: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> Active: (null topology) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:00] DEBUG[2947] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f8ea815cda8 for Response msg 180/INVITE/cseq=29486 (rdata0x7f8e98001568) [Nov 9 09:50:00] DEBUG[2947] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/kamailio-000000f1 associated with dialog dlg0x7f8ea815cda8 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 Method: INVITE Status: 180 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 Event: TSX_STATE Inv State: EARLY [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-00000143)' [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8ea804c8f8) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The current inv state is EARLY [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Source of transaction state change is RX_MSG [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Received response [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Response is 180 Ringing [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143: Status: 180 [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 TSX State: Proceeding Inv State: EARLY [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-00000143)' [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8ea804c8f8) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f8ea804c8f8 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The current transaction state is Proceeding [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The transaction state change event is RX_MSG [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: The current inv state is EARLY [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Response is 180 Ringing [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143: Status: 180 [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143: Queueing RINGING [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143: Status: 180 [Nov 9 09:50:00] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[2922] devicestate.c: No provider found, checking channel drivers for PJSIP - kamailio [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Nothing delayed [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 TSX State: Proceeding Inv State: EARLY [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: Topology: Pending: <0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm)> Active: (null topology) [Nov 9 09:50:00] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:00] DEBUG[2922] devicestate.c: Changing state for PJSIP/kamailio - state 6 (Ringing) [Nov 9 09:50:00] VERBOSE[7447][C-000000db] app_dial.c: PJSIP/kamailio-00000143 is ringing [Nov 9 09:50:00] DEBUG[2922] devicestate.c: No provider found, checking channel drivers for Local - b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 [Nov 9 09:50:00] DEBUG[2922] devicestate.c: Changing state for Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 - state 2 (In use) [Nov 9 09:50:00] VERBOSE[7446] dial.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 is ringing [Nov 9 09:50:00] DEBUG[7451] manager.c: Running action 'Login' [Nov 9 09:50:00] VERBOSE[7451] manager.c: Manager 'b3voice' logged on from 127.0.0.1 [Nov 9 09:50:00] DEBUG[7451] manager.c: Running action 'Redirect' [Nov 9 09:50:00] DEBUG[7451] channel.c: Soft-Hanging (0x02) up channel 'PJSIP/tssbc1_vendor-00000142' [Nov 9 09:50:00] DEBUG[7441][C-000000da] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 9 09:50:00] DEBUG[7441][C-000000da] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 9 09:50:00] DEBUG[7441][C-000000da] channel.c: Channel PJSIP/tssbc1_vendor-00000142 setting write format path: ulaw -> ulaw [Nov 9 09:50:00] DEBUG[7441][C-000000da] pbx.c: Launching 'AGI' [Nov 9 09:50:00] VERBOSE[7441][C-000000da] pbx.c: Executing [unpause@followme:1] AGI("PJSIP/tssbc1_vendor-00000142", "agi://127.0.0.1/ivr_unpause") in new stack [Nov 9 09:50:00] DEBUG[7441][C-000000da] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 09:50:00] DEBUG[7441][C-000000da] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 09:50:00] DEBUG[7441][C-000000da] res_agi.c: Wow, connected! [Nov 9 09:50:00] DEBUG[7441][C-000000da] pbx_variables.c: Result of 'txnId' is '1ab0cf28-7246-4fd5-a12e-47f51f5c8721' [Nov 9 09:50:00] DEBUG[7441][C-000000da] pbx_variables.c: Result of 'legId' is '1edd807e-5fd9-11ed-9302-3364887a6b64' [Nov 9 09:50:00] DEBUG[7441][C-000000da] pbx_variables.c: Result of 'CPLAYBACKSTATUS' is 'ERROR' [Nov 9 09:50:00] VERBOSE[7451] manager.c: Manager 'b3voice' logged off from 127.0.0.1 [Nov 9 09:50:00] VERBOSE[7441][C-000000da] res_agi.c: AGI Script Executing Application: (WAIT) Options: (0.0) [Nov 9 09:50:01] VERBOSE[7441][C-000000da] res_agi.c: AGI Script Executing Application: (RINGING) Options: () [Nov 9 09:50:01] DEBUG[7441][C-000000da] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142: Indicated Ringing [Nov 9 09:50:01] DEBUG[7441][C-000000da] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142 [Nov 9 09:50:01] DEBUG[7441][C-000000da] channel.c: Driver for channel 'PJSIP/tssbc1_vendor-00000142' does not support indication 3, emulating it [Nov 9 09:50:01] DEBUG[7441][C-000000da] channel.c: Channel PJSIP/tssbc1_vendor-00000142 setting write format path: slin -> ulaw [Nov 9 09:50:01] DEBUG[7441][C-000000da] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Nov 9 09:50:01] DEBUG[2922] devicestate.c: No provider found, checking channel drivers for PJSIP - tssbc1_vendor [Nov 9 09:50:01] DEBUG[2922] devicestate.c: Changing state for PJSIP/tssbc1_vendor - state 2 (In use) [Nov 9 09:50:01] VERBOSE[7441][C-000000da] res_agi.c: AGI Script Executing Application: (READ) Options: (dtmfresult,tts/TTS-40ce01080f699164e9512ec48a13c748,1,,1,7) [Nov 9 09:50:01] VERBOSE[7441][C-000000da] app_read.c: Accepting a maximum of 1 digits. [Nov 9 09:50:01] DEBUG[7441][C-000000da] channel.c: Channel PJSIP/tssbc1_vendor-00000142 setting write format path: ulaw -> ulaw [Nov 9 09:50:01] DEBUG[7441][C-000000da] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 9 09:50:01] DEBUG[7441][C-000000da] channel.c: Channel PJSIP/tssbc1_vendor-00000142 setting write format path: gsm -> ulaw [Nov 9 09:50:01] DEBUG[7441][C-000000da] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Nov 9 09:50:01] VERBOSE[7441][C-000000da] file.c: Playing 'tts/TTS-40ce01080f699164e9512ec48a13c748.gsm' (language 'en') [Nov 9 09:50:05] DEBUG[2947] res_pjsip/pjsip_distributor.c: Searching for serializer associated with dialog dlg0x7f8ea815cda8 for Response msg 200/INVITE/cseq=29486 (rdata0x7f8e98001568) [Nov 9 09:50:05] DEBUG[2947] res_pjsip/pjsip_distributor.c: Found serializer pjsip/outsess/kamailio-000000f1 associated with dialog dlg0x7f8ea815cda8 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 Method: INVITE Status: 200 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 Event: TSX_STATE Inv State: CONNECTING [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: Function session_inv_on_state_changed called on event TSX_STATE [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-00000143)' [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8ea804c8f8) [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The current inv state is CONNECTING [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Source of transaction state change is RX_MSG [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Received response [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Response is 200 OK [Nov 9 09:50:05] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143: Status: 200 [Nov 9 09:50:05] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Applying negotiated SDP media stream 'audio' using audio SDP handler [Nov 9 09:50:05] DEBUG[20530] res_pjsip_sdp_rtp.c: PJSIP/kamailio-00000143 Stream: 0:audio-0:audio:sendrecv (alaw|opus|ulaw|g729|gsm) [Nov 9 09:50:05] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80212f0) RTCP ignoring duplicate property [Nov 9 09:50:05] DEBUG[20530] netsock2.c: Splitting '172.21.32.116' into... [Nov 9 09:50:05] DEBUG[20530] netsock2.c: ...host '172.21.32.116' and port ''. [Nov 9 09:50:05] DEBUG[20530] acl.c: For destination '172.21.32.116', our source address is '172.21.16.66'. [Nov 9 09:50:05] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80212f0) RTCP setting address on RTP instance [Nov 9 09:50:05] DEBUG[20530] res_pjsip_sdp_rtp.c: PJSIP/kamailio-00000143 ANSWER [Nov 9 09:50:05] DEBUG[20530] res_pjsip_sdp_rtp.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[20530] rtp_engine.c: Setting tx payload type 8 based on m type on 0x7f8e7c4e8de0 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_sdp_rtp.c: [Nov 9 09:50:05] DEBUG[20530] rtp_engine.c: Copying tx payload mapping 8 (0x7f8ea8014ea8) from 0x7f8e7c4e8de0 to 0x7f8ea80214c8 [Nov 9 09:50:05] DEBUG[20530] rtp_engine.c: Copying tx payload mapping 101 (0x7f8ea809cca8) from 0x7f8e7c4e8de0 to 0x7f8ea80214c8 [Nov 9 09:50:05] DEBUG[20530] channel_internal_api.c: PJSIP/kamailio-00000143: MultistreamFormats: (alaw) [Nov 9 09:50:05] DEBUG[20530] channel_internal_api.c: Set native formats but not topology [Nov 9 09:50:05] DEBUG[20530] res_pjsip_sdp_rtp.c: [Nov 9 09:50:05] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80212f0) DTLS - ast_rtp_activate rtp=0x7f8ea80930c0 - setup and perform DTLS' [Nov 9 09:50:05] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80930c0) DTLS perform handshake - ssl = (nil), setup = 0 [Nov 9 09:50:05] DEBUG[20530] res_rtp_asterisk.c: (0x7f8ea80930c0) DTLS perform handshake - ssl = (nil), setup = 0 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_sdp_rtp.c: Handled [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Applied negotiated SDP media stream 'audio' using audio SDP handler [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Applied negotiated SDP media stream 'audio' using audio SDP handler [Nov 9 09:50:05] DEBUG[20530] channel_internal_api.c: PJSIP/kamailio-00000143: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 09:50:05] DEBUG[20530] channel_internal_api.c: Used provided topology [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[20530] res_pjsip/pjsip_resolver.c: Performing SIP DNS resolution of target '172.21.16.66' [Nov 9 09:50:05] DEBUG[20530] res_pjsip/pjsip_resolver.c: Transport type for target '172.21.16.66' is 'UDP transport' [Nov 9 09:50:05] DEBUG[20530] res_pjsip/pjsip_resolver.c: Target '172.21.16.66' is an IP address, skipping resolution [Nov 9 09:50:05] DEBUG[20530] netsock2.c: Splitting '172.21.16.66' into... [Nov 9 09:50:05] DEBUG[20530] netsock2.c: ...host '172.21.16.66' and port ''. [Nov 9 09:50:05] DEBUG[20530] res_pjsip_nat.c: Request is being sent to local address, skipping NAT manipulation [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 Event: TX_MSG Inv State: CONFIRMED [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: Function session_inv_on_state_changed called on event TX_MSG [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-00000143)' [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The inv session still has an invite_tsx (0x7f8ea804c8f8) [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: There is no transaction involved in this state change [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The current inv state is CONFIRMED [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 TSX State: Terminated Inv State: CONFIRMED [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: Function session_inv_on_tsx_state_changed called on event TSX_STATE [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The state change pertains to the endpoint 'kamailio(PJSIP/kamailio-00000143)' [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The inv session does NOT have an invite_tsx [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The UAC INVITE transaction involved in this state change is 0x7f8ea804c8f8 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The current transaction state is Terminated [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The transaction state change event is RX_MSG [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: The current inv state is CONFIRMED [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143: Response is 200 OK [Nov 9 09:50:05] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143: Status: 200 [Nov 9 09:50:05] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143: Queueing ANSWER [Nov 9 09:50:05] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143: Status: 200 [Nov 9 09:50:05] DEBUG[20530] chan_pjsip.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: Nothing delayed [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: PJSIP/kamailio-00000143 TSX State: Terminated Inv State: CONFIRMED [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: Topology: Pending: (null topology) Active: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 09:50:05] DEBUG[20530] res_pjsip_session.c: [Nov 9 09:50:05] DEBUG[7447][C-000000db] app_dial.c: PJSIP/kamailio-00000143 answered Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 [Nov 9 09:50:05] VERBOSE[7447][C-000000db] app_dial.c: PJSIP/kamailio-00000143 answered Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 [Nov 9 09:50:05] DEBUG[7447][C-000000db] app_dial.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2: Answered by PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 setting write format path: slin -> slin [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 setting read format path: slin -> slin [Nov 9 09:50:05] DEBUG[7447][C-000000db] core_unreal.c: Blocked indication -1 [Nov 9 09:50:05] DEBUG[7447][C-000000db] stasis.c: Creating topic. name: bridge:all/bridge:b41ecfa7-31ce-4245-8d09-f5cdfbe01c93, detail: [Nov 9 09:50:05] DEBUG[7447][C-000000db] stasis.c: Topic 'bridge:all/bridge:b41ecfa7-31ce-4245-8d09-f5cdfbe01c93': 0x7f8ea80e0f80 created [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge_native_rtp.c: Bridge 'b41ecfa7-31ce-4245-8d09-f5cdfbe01c93' can not use native RTP bridge as two channels are required [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Chose bridge technology simple_bridge [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: calling simple_bridge technology constructor [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: calling simple_bridge technology start [Nov 9 09:50:05] DEBUG[7447][C-000000db] stasis_bridges.c: Update: 0x7f8ea80e36b8 Old: New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] VERBOSE[7446] dial.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 answered [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx.c: Launching 'AGI' [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] pbx.c: Executing [b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg2:1] AGI("Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1", "agi://127.0.0.1/dial") in new stack [Nov 9 09:50:05] DEBUG[7446][C-000000dc] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 09:50:05] DEBUG[7446][C-000000dc] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] res_agi.c: Wow, connected! [Nov 9 09:50:05] DEBUG[2981] pbx_spool.c: Filename: /var/spool/asterisk/outgoing/apicall.b6dcafa4-1587-4514-8eca-11d984752ac9, Retries: 0, max: 0 [Nov 9 09:50:05] DEBUG[2981] pbx_spool.c: Outgoing Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1: DelayedRetry [Nov 9 09:50:05] DEBUG[2981] pbx_spool.c: Delaying retry since we're currently running '/var/spool/asterisk/outgoing/apicall.b6dcafa4-1587-4514-8eca-11d984752ac9' [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8ea80e36b8 Old: New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[2922] devicestate.c: No provider found, checking channel drivers for PJSIP - kamailio [Nov 9 09:50:05] DEBUG[2922] devicestate.c: Changing state for PJSIP/kamailio - state 2 (In use) [Nov 9 09:50:05] DEBUG[2922] devicestate.c: No provider found, checking channel drivers for Local - b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 [Nov 9 09:50:05] DEBUG[2922] devicestate.c: Changing state for Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 - state 2 (In use) [Nov 9 09:50:05] DEBUG[2922] devicestate.c: No provider found, checking channel drivers for Local - b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 [Nov 9 09:50:05] DEBUG[2922] devicestate.c: Changing state for Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 - state 2 (In use) [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx_variables.c: Result of 'txnId' is 'b6dcafa4-1587-4514-8eca-11d984752ac9' [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx_variables.c: Result of 'CHANNEL' is 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1' [Nov 9 09:50:05] DEBUG[7460][C-000000db] bridge_channel.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: 0x7f8ea80e3c00(PJSIP/kamailio-00000143) is joining [Nov 9 09:50:05] DEBUG[7460][C-000000db] bridge_channel.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: pushing 0x7f8ea80e3c00(PJSIP/kamailio-00000143) [Nov 9 09:50:05] VERBOSE[7460][C-000000db] bridge_channel.c: Channel PJSIP/kamailio-00000143 joined 'simple_bridge' basic-bridge [Nov 9 09:50:05] DEBUG[7460][C-000000db] stasis_bridges.c: Update: 0x7f8ec400a558 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[7460][C-000000db] stasis_bridges.c: Update: 0x7f8ec400a558 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[7460][C-000000db] bridge_native_rtp.c: Bridge 'b41ecfa7-31ce-4245-8d09-f5cdfbe01c93' can not use native RTP bridge as two channels are required [Nov 9 09:50:05] DEBUG[7460][C-000000db] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 09:50:05] DEBUG[7460][C-000000db] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7460][C-000000db] bridge.c: Bridge technology softmix does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7460][C-000000db] bridge.c: Chose bridge technology simple_bridge [Nov 9 09:50:05] DEBUG[7460][C-000000db] bridge.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 is already using the new technology. [Nov 9 09:50:05] DEBUG[7460][C-000000db] bridge.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: 0x7f8ea80e3c00(PJSIP/kamailio-00000143) is joining simple_bridge technology [Nov 9 09:50:05] DEBUG[7460][C-000000db] stasis_bridges.c: Update: 0x7f8ec400a998 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[7460][C-000000db] stasis_bridges.c: Update: 0x7f8ec400a998 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge_channel.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: 0x7f8ea80a6d90(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2) is joining [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge_channel.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: pushing 0x7f8ea80a6d90(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2) [Nov 9 09:50:05] VERBOSE[7447][C-000000db] bridge_channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 joined 'simple_bridge' basic-bridge [Nov 9 09:50:05] DEBUG[7447][C-000000db] stasis_bridges.c: Update: 0x7f8ea80e1528 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge_native_rtp.c: Bridge 'b41ecfa7-31ce-4245-8d09-f5cdfbe01c93'. Checking compatability for channels 'PJSIP/kamailio-00000143' and 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge_native_rtp.c: Bridge 'b41ecfa7-31ce-4245-8d09-f5cdfbe01c93' can not use native RTP bridge as could not get details [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Bridge technology softmix does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Chose bridge technology simple_bridge [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 is already using the new technology. [Nov 9 09:50:05] DEBUG[7447][C-000000db] bridge.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: 0x7f8ea80a6d90(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2) is joining simple_bridge technology [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 setting read format path: slin -> slin [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 setting write format path: slin -> slin [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2: Topologies already match. Current: <0:audio-0:audio:sendrecv (slin)> Requested: <0:audio-0:audio:sendrecv (slin)> [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel.c: PJSIP/kamailio-00000143: Topologies already match. Current: <0:audio-0:audio:sendrecv (alaw)> Requested: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 09:50:05] DEBUG[7447][C-000000db] stasis_bridges.c: Update: 0x7f8ea80278f8 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8ea80e1528 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8ea80278f8 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[7460][C-000000db] chan_pjsip.c: PJSIP/kamailio-00000143: Indicated Media SSRC change [Nov 9 09:50:05] DEBUG[7460][C-000000db] chan_pjsip.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] app_stack.c: Gosub args:api_ivr_leg2,leghangup,1 new_args:api_ivr_leg2,leghangup,1 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx_variables.c: Result of 'legId' is 'Local-api_ivr_leg2-b6dcafa4-1587-4514-8eca-11d984752ac9' [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx_variables.c: Result of 'CONTEXT' is 'api_ivr_leg2' [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx_variables.c: Result of 'CONTEXT' is 'api_ivr_leg2' [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] res_agi.c: AGI Script Executing Application: (BRIDGE) Options: (PJSIP/tssbc1_vendor-00000142,x) [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis.c: Creating topic. name: bridge:all/bridge:71519064-208b-486e-b8cc-b825af89560e, detail: [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis.c: Topic 'bridge:all/bridge:71519064-208b-486e-b8cc-b825af89560e': 0x7f8eb00101d0 created [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_native_rtp.c: Bridge '71519064-208b-486e-b8cc-b825af89560e' can not use native RTP bridge as two channels are required [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology softmix has less preference than simple_bridge (10 <= 50). Skipping. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Chose bridge technology simple_bridge [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: calling simple_bridge technology constructor [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: calling simple_bridge technology start [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis_bridges.c: Update: 0x7f8eb0006c08 Old: New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel_internal_api.c: : Formats: (none) [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis.c: Creating topic. name: channel:1667962205.385, detail: [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis.c: Topic 'channel:1667962205.385': 0x7f8eb0018590 created [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel 0x7f8eb0014fc0 'Surrogate/PJSIP/tssbc1_vendor-00000142' allocated [Nov 9 09:50:05] DEBUG[7446][C-000000dc] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142: Indicated Masquerade notify [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8eb0006c08 Old: New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[7446][C-000000dc] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Actually Masquerading PJSIP/tssbc1_vendor-00000142(6) into the structure of Surrogate/PJSIP/tssbc1_vendor-00000142(0) [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel_internal_api.c: PJSIP/tssbc1_vendor-00000142: MultistreamFormats: (ulaw) [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel_internal_api.c: Set native formats but not topology [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel PJSIP/tssbc1_vendor-00000142 setting write format path: gsm -> ulaw [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel PJSIP/tssbc1_vendor-00000142 setting read format path: ulaw -> ulaw [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Putting channel PJSIP/tssbc1_vendor-00000142 in gsm/ulaw formats [Nov 9 09:50:05] DEBUG[7446][C-000000dc] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142: Indicated Masquerade notify [Nov 9 09:50:05] DEBUG[7446][C-000000dc] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142 [Nov 9 09:50:05] DEBUG[7441][C-000000da] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 9 09:50:05] DEBUG[7441][C-000000da] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Nov 9 09:50:05] DEBUG[7441][C-000000da] channel.c: Channel Surrogate/PJSIP/tssbc1_vendor-00000142 setting write format path: ulaw -> ulaw [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Done Masquerading PJSIP/tssbc1_vendor-00000142 (6) [Nov 9 09:50:05] DEBUG[7446][C-000000dc] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142: Indicated Media SSRC change [Nov 9 09:50:05] DEBUG[7446][C-000000dc] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142 [Nov 9 09:50:05] DEBUG[7463][C-000000dc] bridge_channel.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: 0x7f8eb0014bc0(PJSIP/tssbc1_vendor-00000142) is joining [Nov 9 09:50:05] DEBUG[7463][C-000000dc] bridge_channel.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: pushing 0x7f8eb0014bc0(PJSIP/tssbc1_vendor-00000142) [Nov 9 09:50:05] VERBOSE[7463][C-000000dc] bridge_channel.c: Channel PJSIP/tssbc1_vendor-00000142 joined 'simple_bridge' basic-bridge <71519064-208b-486e-b8cc-b825af89560e> [Nov 9 09:50:05] DEBUG[7463][C-000000dc] stasis_bridges.c: Update: 0x7f8ec0001d38 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[7463][C-000000dc] bridge_native_rtp.c: Bridge '71519064-208b-486e-b8cc-b825af89560e' can not use native RTP bridge as two channels are required [Nov 9 09:50:05] DEBUG[7463][C-000000dc] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 09:50:05] DEBUG[7463][C-000000dc] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7463][C-000000dc] bridge.c: Bridge technology softmix does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7463][C-000000dc] bridge.c: Chose bridge technology simple_bridge [Nov 9 09:50:05] DEBUG[7463][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e is already using the new technology. [Nov 9 09:50:05] DEBUG[7463][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: 0x7f8eb0014bc0(PJSIP/tssbc1_vendor-00000142) is joining simple_bridge technology [Nov 9 09:50:05] DEBUG[7463][C-000000dc] stasis_bridges.c: Update: 0x7f8ec0001d08 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_channel.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: 0x7f8eb0014d60(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1) is joining [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_channel.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: pushing 0x7f8eb0014d60(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1) [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8ec0001d38 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8ec0001d08 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] bridge_channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 joined 'simple_bridge' basic-bridge <71519064-208b-486e-b8cc-b825af89560e> [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis_bridges.c: Update: 0x7f8eb0005c48 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_native_rtp.c: Bridge '71519064-208b-486e-b8cc-b825af89560e'. Checking compatability for channels 'PJSIP/tssbc1_vendor-00000142' and 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1' [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8eb0005c48 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_native_rtp.c: Bridge '71519064-208b-486e-b8cc-b825af89560e' can not use native RTP bridge as could not get details [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology softmix does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Chose bridge technology simple_bridge [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e is already using the new technology. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: 0x7f8eb0014d60(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1) is joining simple_bridge technology [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 setting read format path: slin -> slin [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel PJSIP/tssbc1_vendor-00000142 setting write format path: slin -> ulaw [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel PJSIP/tssbc1_vendor-00000142 setting read format path: ulaw -> slin [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 setting write format path: slin -> slin [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1: Topologies already match. Current: <0:audio-0:audio:sendrecv (slin)> Requested: <0:audio-0:audio:sendrecv (slin)> [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: PJSIP/tssbc1_vendor-00000142: Topologies already match. Current: <0:audio-0:audio:sendrecv (ulaw)> Requested: <0:audio-0:audio:sendrecv (ulaw)> [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis_bridges.c: Update: 0x7f8eb00109d8 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8eb00109d8 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[7463][C-000000dc] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142: Indicated Media SSRC change [Nov 9 09:50:05] DEBUG[7460][C-000000db] chan_pjsip.c: PJSIP/kamailio-00000143: Indicated Media SSRC change [Nov 9 09:50:05] DEBUG[7460][C-000000db] chan_pjsip.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[7460][C-000000db] chan_pjsip.c: PJSIP/kamailio-00000143: Indicated Connected line update [Nov 9 09:50:05] DEBUG[7460][C-000000db] chan_pjsip.c: PJSIP/kamailio-00000143 [Nov 9 09:50:05] DEBUG[7463][C-000000dc] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142 [Nov 9 09:50:05] DEBUG[7463][C-000000dc] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142: Indicated Connected line update [Nov 9 09:50:05] DEBUG[7463][C-000000dc] chan_pjsip.c: PJSIP/tssbc1_vendor-00000142 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Moving 0x7f8eb0014bc0(PJSIP/tssbc1_vendor-00000142) into bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 swapping with Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_channel.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: pulling 0x7f8eb0014bc0(PJSIP/tssbc1_vendor-00000142) [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] bridge_channel.c: Channel PJSIP/tssbc1_vendor-00000142 left 'simple_bridge' basic-bridge <71519064-208b-486e-b8cc-b825af89560e> [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_channel.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: 0x7f8eb0014bc0(PJSIP/tssbc1_vendor-00000142) is leaving simple_bridge technology [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis_bridges.c: Update: 0x7f8eb0004a88 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8eb0004a88 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_channel.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: pushing 0x7f8eb0014bc0(PJSIP/tssbc1_vendor-00000142) by swapping with 0x7f8ea80a6d90(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2) [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_channel.c: Setting 0x7f8ea80a6d90(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2) state from:0 to:2 [Nov 9 09:50:05] VERBOSE[7441][C-000000da] app_read.c: User disconnected [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_channel.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: pulling 0x7f8ea80a6d90(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2) [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] bridge_channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 left 'simple_bridge' basic-bridge [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_channel.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: 0x7f8ea80a6d90(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2) is leaving simple_bridge technology [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis_bridges.c: Update: 0x7f8eb0017778 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] bridge_channel.c: Channel PJSIP/tssbc1_vendor-00000142 swapped with Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 into 'simple_bridge' basic-bridge [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis_bridges.c: Update: 0x7f8eb0024ae8 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[7441][C-000000da] res_agi.c: Surrogate/PJSIP/tssbc1_vendor-00000142 hungup [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_native_rtp.c: Bridge 'b41ecfa7-31ce-4245-8d09-f5cdfbe01c93'. Checking compatability for channels 'PJSIP/kamailio-00000143' and 'PJSIP/tssbc1_vendor-00000142' [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_native_rtp.c: Bridge 'b41ecfa7-31ce-4245-8d09-f5cdfbe01c93' can not use native RTP bridge as channel 'PJSIP/kamailio-00000143' has DTMF hooks [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology softmix does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Chose bridge technology simple_bridge [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 is already using the new technology. [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8eb0017778 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge b41ecfa7-31ce-4245-8d09-f5cdfbe01c93: 0x7f8eb0014bc0(PJSIP/tssbc1_vendor-00000142) is joining simple_bridge technology [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel PJSIP/tssbc1_vendor-00000142 setting read format path: ulaw -> ulaw [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel PJSIP/kamailio-00000143 setting write format path: ulaw -> alaw [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8eb0024ae8 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel PJSIP/kamailio-00000143 setting read format path: alaw -> alaw [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel PJSIP/tssbc1_vendor-00000142 setting write format path: alaw -> ulaw [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: PJSIP/tssbc1_vendor-00000142: Topologies already match. Current: <0:audio-0:audio:sendrecv (ulaw)> Requested: <0:audio-0:audio:sendrecv (ulaw)> [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: PJSIP/kamailio-00000143: Topologies already match. Current: <0:audio-0:audio:sendrecv (alaw)> Requested: <0:audio-0:audio:sendrecv (alaw)> [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis_bridges.c: Update: 0x7f8eb0017718 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_native_rtp.c: Bridge '71519064-208b-486e-b8cc-b825af89560e' can not use native RTP bridge as two channels are required [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8eb0017718 Old: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 New: b41ecfa7-31ce-4245-8d09-f5cdfbe01c93 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology native_rtp is not compatible with properties of existing bridge. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology holding_bridge does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge technology softmix does not have any capabilities we want. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Chose bridge technology simple_bridge [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e is already using the new technology. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis_bridges.c: Update: 0x7f8eb0021a18 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_channel.c: Setting 0x7f8eb0014d60(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1) state from:0 to:2 [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8eb0021a18 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_channel.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: pulling 0x7f8eb0014d60(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1) [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] bridge_channel.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 left 'simple_bridge' basic-bridge <71519064-208b-486e-b8cc-b825af89560e> [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge_channel.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: 0x7f8eb0014d60(Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1) is leaving simple_bridge technology [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: dissolving bridge with cause 16(Normal Clearing) [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: queueing action type:13 sub:1001 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis_bridges.c: Update: 0x7f8eb0021a18 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[7446][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e is dissolved, not performing smart bridge operation. [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8eb0021a18 Old: 71519064-208b-486e-b8cc-b825af89560e New: 71519064-208b-486e-b8cc-b825af89560e [Nov 9 09:50:05] DEBUG[2921][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: actually destroying basic bridge, nobody wants it anymore [Nov 9 09:50:05] DEBUG[2921][C-000000dc] stasis_bridges.c: Update: 0x7f8ea000d318 Old: 71519064-208b-486e-b8cc-b825af89560e New: [Nov 9 09:50:05] DEBUG[2921][C-000000dc] stasis.c: Destroying topic. name: bridge:all/bridge:71519064-208b-486e-b8cc-b825af89560e, detail: [Nov 9 09:50:05] DEBUG[2921][C-000000dc] stasis.c: Topic 'bridge:all/bridge:71519064-208b-486e-b8cc-b825af89560e': 0x7f8eb00101d0 destroyed [Nov 9 09:50:05] DEBUG[2921][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: calling basic bridge destructor [Nov 9 09:50:05] DEBUG[2921][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: calling simple_bridge technology stop [Nov 9 09:50:05] DEBUG[2921][C-000000dc] bridge.c: Bridge 71519064-208b-486e-b8cc-b825af89560e: calling simple_bridge technology destructor [Nov 9 09:50:05] DEBUG[7446][C-000000dc] res_agi.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 hungup [Nov 9 09:50:05] DEBUG[7447][C-000000db] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Nov 9 09:50:05] DEBUG[7447][C-000000db] app_dial.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2: Done [Nov 9 09:50:05] DEBUG[7447][C-000000db] pbx.c: Spawn extension (api_ivr_leg1,attempt,1) exited non-zero on 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' [Nov 9 09:50:05] VERBOSE[7447][C-000000db] pbx.c: Spawn extension (api_ivr_leg1, attempt, 1) exited non-zero on 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel.c: Soft-Hanging (0x10) up channel 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel.c: Soft-Hanging (0x80) up channel 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' [Nov 9 09:50:05] VERBOSE[7447][C-000000db] app_stack.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 Internal Gosub(api_ivr_leg1,leghangup,1) start [Nov 9 09:50:05] DEBUG[7447][C-000000db] app_stack.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 Original location: api_ivr_leg1,attempt,1 [Nov 9 09:50:05] DEBUG[7447][C-000000db] app_stack.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 has no datastore, so we're allocating one. [Nov 9 09:50:05] DEBUG[7447][C-000000db] app_stack.c: Gosub exited with status 0 [Nov 9 09:50:05] DEBUG[7447][C-000000db] pbx.c: Launching 'AGI' [Nov 9 09:50:05] VERBOSE[7447][C-000000db] pbx.c: Executing [leghangup@api_ivr_leg1:1] AGI("Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2", "agi://127.0.0.1/leghangup") in new stack [Nov 9 09:50:05] DEBUG[7447][C-000000db] res_agi.c: Hungup channel detected, running agi in dead mode. [Nov 9 09:50:05] DEBUG[7447][C-000000db] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 09:50:05] DEBUG[7447][C-000000db] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 09:50:05] DEBUG[2941] stasis_bridges.c: Update: 0x7f8ea000d318 Old: 71519064-208b-486e-b8cc-b825af89560e New: [Nov 9 09:50:05] DEBUG[7447][C-000000db] res_agi.c: Wow, connected! [Nov 9 09:50:05] DEBUG[2910] threadpool.c: Increasing threadpool stasis/pool's size by 1 [Nov 9 09:50:05] DEBUG[7441][C-000000da] pbx_variables.c: Result of 'READSTATUS' is 'HANGUP' [Nov 9 09:50:05] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'txnId' is 'b6dcafa4-1587-4514-8eca-11d984752ac9' [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] res_agi.c: AGI Script agi://127.0.0.1/dial completed, returning 4 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] utils.c: write() failed due to reading end being closed: Broken pipe [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx.c: Spawn extension (api_ivr_leg2,b6dcafa4-1587-4514-8eca-11d984752ac9,1) exited non-zero on 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1' [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] pbx.c: Spawn extension (api_ivr_leg2, b6dcafa4-1587-4514-8eca-11d984752ac9, 1) exited non-zero on 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1' [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Soft-Hanging (0x10) up channel 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1' [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Soft-Hanging (0x80) up channel 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1' [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] app_stack.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 Internal Gosub(api_ivr_leg2,leghangup,1) start [Nov 9 09:50:05] DEBUG[7446][C-000000dc] app_stack.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 Original location: api_ivr_leg2,b6dcafa4-1587-4514-8eca-11d984752ac9,1 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] app_stack.c: Channel Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 has no datastore, so we're allocating one. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] app_stack.c: Gosub exited with status 0 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx.c: Launching 'AGI' [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] pbx.c: Executing [leghangup@api_ivr_leg2:1] AGI("Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1", "agi://127.0.0.1/leghangup") in new stack [Nov 9 09:50:05] DEBUG[7446][C-000000dc] res_agi.c: Hungup channel detected, running agi in dead mode. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] netsock2.c: Splitting '127.0.0.1' into... [Nov 9 09:50:05] DEBUG[7446][C-000000dc] netsock2.c: ...host '127.0.0.1' and port ''. [Nov 9 09:50:05] DEBUG[7446][C-000000dc] res_agi.c: Wow, connected! [Nov 9 09:50:05] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'legId' is 'Local-api_ivr_leg1-b6dcafa4-1587-4514-8eca-11d984752ac9' [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx_variables.c: Result of 'txnId' is 'b6dcafa4-1587-4514-8eca-11d984752ac9' [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx_variables.c: Result of 'legId' is 'Local-api_ivr_leg2-b6dcafa4-1587-4514-8eca-11d984752ac9' [Nov 9 09:50:05] DEBUG[7447][C-000000db] pbx_variables.c: Result of 'MIXMONITOR_FILENAME' is NULL [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx_variables.c: Result of 'MIXMONITOR_FILENAME' is NULL [Nov 9 09:50:05] VERBOSE[7447][C-000000db] res_agi.c: AGI Script agi://127.0.0.1/leghangup completed, returning 0 [Nov 9 09:50:05] DEBUG[7447][C-000000db] pbx.c: Launching 'Return' [Nov 9 09:50:05] VERBOSE[7447][C-000000db] pbx.c: Executing [leghangup@api_ivr_leg1:2] Return("Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2", "") in new stack [Nov 9 09:50:05] DEBUG[7447][C-000000db] app_stack.c: Spawn extension (api_ivr_leg1,attempt,1) exited with -1 on 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' [Nov 9 09:50:05] VERBOSE[7447][C-000000db] app_stack.c: Spawn extension (api_ivr_leg1, attempt, 1) exited non-zero on 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' [Nov 9 09:50:05] VERBOSE[7447][C-000000db] app_stack.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 Internal Gosub(api_ivr_leg1,leghangup,1) complete GOSUB_RETVAL= [Nov 9 09:50:05] DEBUG[7447][C-000000db] app_stack.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2 Ending location: api_ivr_leg1,attempt,1 [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel.c: Channel 0x7f8eb000d0e0 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' hanging up. Refs: 2 [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel.c: Channel 0x7f8eb000d0e0 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;2' destroying [Nov 9 09:50:05] DEBUG[7447][C-000000db] stasis.c: Destroying topic. name: channel:1667962200.383, detail: [Nov 9 09:50:05] DEBUG[7447][C-000000db] stasis.c: Topic 'channel:1667962200.383': 0x7f8eb000a580 destroyed [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel_internal_api.c: : MultistreamFormats: (nothing) [Nov 9 09:50:05] DEBUG[7447][C-000000db] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 09:50:05] DEBUG[2922] devicestate.c: No provider found, checking channel drivers for Local - b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 [Nov 9 09:50:05] DEBUG[2922] devicestate.c: Changing state for Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 - state 1 (Not in use) [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] res_agi.c: AGI Script agi://127.0.0.1/leghangup completed, returning 0 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] pbx.c: Launching 'Return' [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] pbx.c: Executing [leghangup@api_ivr_leg2:2] Return("Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1", "") in new stack [Nov 9 09:50:05] DEBUG[7446][C-000000dc] app_stack.c: Spawn extension (api_ivr_leg2,b6dcafa4-1587-4514-8eca-11d984752ac9,1) exited with -1 on 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1' [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] app_stack.c: Spawn extension (api_ivr_leg2, b6dcafa4-1587-4514-8eca-11d984752ac9, 1) exited non-zero on 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1' [Nov 9 09:50:05] VERBOSE[7446][C-000000dc] app_stack.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 Internal Gosub(api_ivr_leg2,leghangup,1) complete GOSUB_RETVAL= [Nov 9 09:50:05] DEBUG[7446][C-000000dc] app_stack.c: Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1 Ending location: api_ivr_leg2,b6dcafa4-1587-4514-8eca-11d984752ac9,1 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel 0x7f8eb0016760 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1' hanging up. Refs: 2 [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel.c: Channel 0x7f8eb0016760 'Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1-00000018;1' destroying [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis.c: Destroying topic. name: channel:1667962200.382, detail: [Nov 9 09:50:05] DEBUG[7446][C-000000dc] stasis.c: Topic 'channel:1667962200.382': 0x7f8eb0010f40 destroyed [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel_internal_api.c: : MultistreamFormats: (nothing) [Nov 9 09:50:05] DEBUG[7446][C-000000dc] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 09:50:05] DEBUG[2922] devicestate.c: No provider found, checking channel drivers for Local - b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 [Nov 9 09:50:05] NOTICE[7446][C-000000dc] pbx_spool.c: Call completed to Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 [Nov 9 09:50:05] DEBUG[2922] core_local.c: Checking if extension b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 exists (devicestate) [Nov 9 09:50:05] DEBUG[2922] devicestate.c: Changing state for Local/b6dcafa4-1587-4514-8eca-11d984752ac9@api_ivr_leg1 - state 1 (Not in use) [Nov 9 09:50:05] DEBUG[7460][C-000000db] res_rtp_asterisk.c: (0x7f8ea80212f0) RTP ooh, format changed from none to alaw [Nov 9 09:50:05] VERBOSE[7441][C-000000da] res_agi.c: AGI Script agi://127.0.0.1/ivr_unpause completed, returning 4 [Nov 9 09:50:05] DEBUG[7441][C-000000da] pbx.c: Spawn extension (followme,unpause,1) exited non-zero on 'Surrogate/PJSIP/tssbc1_vendor-00000142' [Nov 9 09:50:05] VERBOSE[7441][C-000000da] pbx.c: Spawn extension (followme, unpause, 1) exited non-zero on 'Surrogate/PJSIP/tssbc1_vendor-00000142' [Nov 9 09:50:05] DEBUG[7441][C-000000da] channel.c: Soft-Hanging (0x10) up channel 'Surrogate/PJSIP/tssbc1_vendor-00000142' [Nov 9 09:50:05] DEBUG[7441][C-000000da] channel.c: Channel 0x7f8ea8026a40 'Surrogate/PJSIP/tssbc1_vendor-00000142' hanging up. Refs: 2 [Nov 9 09:50:05] DEBUG[7441][C-000000da] channel.c: Channel 0x7f8ea8026a40 'Surrogate/PJSIP/tssbc1_vendor-00000142' destroying [Nov 9 09:50:05] DEBUG[7441][C-000000da] stasis.c: Destroying topic. name: channel:1667962205.385, detail: [Nov 9 09:50:05] DEBUG[7441][C-000000da] stasis.c: Topic 'channel:1667962205.385': 0x7f8eb0018590 destroyed [Nov 9 09:50:05] DEBUG[7441][C-000000da] channel_internal_api.c: : Formats: (nothing) [Nov 9 09:50:05] DEBUG[7441][C-000000da] channel_internal_api.c: Channel is being initialized or destroyed [Nov 9 09:50:05] DEBUG[2922] devicestate.c: No provider found, checking channel drivers for Surrogate - PJSIP/tssbc1_vendor [Nov 9 09:50:05] DEBUG[2922] devicestate.c: Changing state for Surrogate/PJSIP/tssbc1_vendor - state 0 (Unknown)