FusionPBX 4.4 CDRs cause problem when turn off 407 authentication calls

Status
Not open for further replies.

Minh Tuan

New Member
Jun 6, 2019
6
0
1
25
Hi all, I'm trying to run OpenSIPs with FusionPBX becasue our FusionPBX seem to have some problem when reaching about 400 concurrent calls, the biggest problem is FreeSWITCH doesn't response to any SIP message, but service FreeSWITCH still active and FreeSWITCH port still open.

SIP model is something like this
Client -> OpenSIPs -> FusionPBX -> PSTN
OpenSIPs is running with mid-registrar, right now the SIP message flow is running fine, like this
Now I want to turn off 407 Proxy Authentication Required, I'm doing that by put OpenSIPs IP into ACL on FusionPBX, and create an dialplan to change context from public to the right context of that domain
So the SIP message flow is like this
This is the SIP message flow I wanted but there is something wrong with FusionPBX CDRs when the CDRs without 407 will missing extension_uuid compare to CDRs with 407, I've turn on debug in /etc/fusionpbx/config.lua and capture FreeSWITCH log below
2022-02-17 11:09:36.161208 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/101@dev.mtuan.com [8b761da4-a00a-4ab6-9a5a-6146d05bb62e]
2022-02-17 11:09:36.161208 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/101@dev.mtuan.com) Running State Change CS_NEW (Cur 1 Tot 1)
2022-02-17 11:09:36.161208 [INFO] sofia.c:10362 sofia/internal/101@dev.mtuan.com receiving invite from 157.119.251.207:5060 version: 1.10.6-release git 1ff9d0a 2021-03-25 13:16:09Z 64bit call-id: 36f02684a33547d2bcc4935f79da0571
2022-02-17 11:09:36.161208 [DEBUG] sofia.c:10456 verifying acl "domains" for ip/port 157.119.251.207:0.
2022-02-17 11:09:36.161208 [DEBUG] sofia.c:10485 IP 157.119.251.207 Approved by acl "domains[]". Access Granted.
2022-02-17 11:09:36.181196 [DEBUG] sofia.c:7406 Channel sofia/internal/101@dev.mtuan.com entering state [received][100]
2022-02-17 11:09:36.181196 [DEBUG] sofia.c:7416 Remote SDP:
v=0
o=- 3854084978 3854084978 IN IP4 192.168.2.19
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4010 RTP/AVP 0 8 9 96 97 98 99 100 4 18 3 101 102 103
c=IN IP4 192.168.2.19
b=TIAS:64000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:9 G722/8000
a=rtpmap:96 G7221/16000
a=fmtp:96 bitrate=24000
a=rtpmap:97 G7221/16000
a=fmtp:97 bitrate=32000
a=rtpmap:98 G7221/32000
a=fmtp:98 bitrate=48000
a=rtpmap:99 G7221/32000
a=fmtp:99 bitrate=24000
a=rtpmap:100 G7221/32000
a=fmtp:100 bitrate=32000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:102 telephone-event/16000
a=fmtp:102 0-16
a=rtpmap:103 telephone-event/32000
a=fmtp:103 0-16
a=rtcp:4011 IN IP4 192.168.2.19
a=ssrc:631720330 cname:785b5ee55308074c

2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5656 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5656 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G7221:96:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G7221:96:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G7221:97:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G7221:97:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G7221:98:32000:20:0:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G7221:98:32000:20:0:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G7221:99:32000:20:0:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G7221:99:32000:20:0:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G7221:100:32000:20:0:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G7221:100:32000:20:0:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G723:4:8000:30:6300:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G723:4:8000:30:6300:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5517 Set telephone-event payload to 101@8000
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:3847 Set Codec sofia/internal/101@dev.mtuan.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2022-02-17 11:09:36.181196 [DEBUG] switch_core_codec.c:111 sofia/internal/101@dev.mtuan.com Original read codec set to PCMU:0
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5860 Set telephone-event payload to 101@8000
2022-02-17 11:09:36.181196 [DEBUG] switch_core_media.c:5918 sofia/internal/101@dev.mtuan.com Set 2833 dtmf send payload to 101 recv payload to 101
2022-02-17 11:09:36.181196 [DEBUG] sofia.c:7840 (sofia/internal/101@dev.mtuan.com) State Change CS_NEW -> CS_INIT
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:604 (sofia/internal/101@dev.mtuan.com) State NEW
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/101@dev.mtuan.com) Running State Change CS_INIT (Cur 1 Tot 1)
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/101@dev.mtuan.com) State INIT
2022-02-17 11:09:36.181196 [DEBUG] mod_sofia.c:93 sofia/internal/101@dev.mtuan.com SOFIA INIT
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:40 sofia/internal/101@dev.mtuan.com Standard INIT
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/101@dev.mtuan.com) State Change CS_INIT -> CS_ROUTING
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/101@dev.mtuan.com) State INIT going to sleep
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/101@dev.mtuan.com) Running State Change CS_ROUTING (Cur 1 Tot 1)
2022-02-17 11:09:36.181196 [DEBUG] switch_channel.c:2332 (sofia/internal/101@dev.mtuan.com) Callstate Change DOWN -> RINGING
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/101@dev.mtuan.com) State ROUTING
2022-02-17 11:09:36.181196 [DEBUG] mod_sofia.c:154 sofia/internal/101@dev.mtuan.com SOFIA ROUTING
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:236 sofia/internal/101@dev.mtuan.com Standard ROUTING
2022-02-17 11:09:36.181196 [INFO] mod_dialplan_xml.c:637 Processing 101 <101>->0965138057 in context public
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler]/usr/local/freeswitch/scripts/app/xml_handler/index.lua
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 TuanTuanTuan [xml_handler] Params:
Event-Name: REQUEST_PARAMS
Core-UUID: 96e24b75-0f60-42cb-a86e-d163d5e68acd
FreeSWITCH-Hostname: fs-node-01
FreeSWITCH-Switchname: cluster-fs
FreeSWITCH-IPv4: 157.119.251.219
FreeSWITCH-IPv6: %3A%3A1
Event-Date-Local: 2022-02-17%2011%3A09%3A36
Event-Date-GMT: Thu,%2017%20Feb%202022%2004%3A09%3A36%20GMT
Event-Date-Timestamp: 1645070976181196
Event-Calling-File: mod_dialplan_xml.c
Event-Calling-Function: dialplan_xml_locate
Event-Calling-Line-Number: 608
Event-Sequence: 650
Channel-State: CS_ROUTING
Channel-Call-State: RINGING
Channel-State-Number: 2
Channel-Name: sofia/internal/101%40dev.mtuan.com
Unique-ID: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
Call-Direction: inbound
Presence-Call-Direction: inbound
Channel-HIT-Dialplan: true
Channel-Presence-ID: 101%40dev.mtuan.com
Channel-Call-UUID: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
Answer-State: ringing
Channel-Read-Codec-Name: PCMU
Channel-Read-Codec-Rate: 8000
Channel-Read-Codec-Bit-Rate: 64000
Channel-Write-Codec-Name: PCMU
Channel-Write-Codec-Rate: 8000
Channel-Write-Codec-Bit-Rate: 64000
Caller-Direction: inbound
Caller-Logical-Direction: inbound
Caller-Username: 101
Caller-Dialplan: XML
Caller-Caller-ID-Name: 101
Caller-Caller-ID-Number: 101
Caller-Orig-Caller-ID-Name: 101
Caller-Orig-Caller-ID-Number: 101
Caller-Network-Addr: 157.119.251.207
Caller-ANI: 101
Caller-Destination-Number: 0965138057
Caller-Unique-ID: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
Caller-Source: mod_sofia
Caller-Context: public
Caller-Channel-Name: sofia/internal/101%40dev.mtuan.com
Caller-Profile-Index: 1
Caller-Profile-Created-Time: 1645070976161208
Caller-Channel-Created-Time: 1645070976161208
Caller-Channel-Answered-Time: 0
Caller-Channel-Progress-Time: 0
Caller-Channel-Progress-Media-Time: 0
Caller-Channel-Hangup-Time: 0
Caller-Channel-Transfer-Time: 0
Caller-Channel-Resurrect-Time: 0
Caller-Channel-Bridged-Time: 0
Caller-Channel-Last-Hold: 0
Caller-Channel-Hold-Accum: 0
Caller-Screen-Bit: true
Caller-Privacy-Hide-Name: false
Caller-Privacy-Hide-Number: false
variable_direction: inbound
variable_uuid: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
variable_session_id: 1
variable_sip_from_user: 101
variable_sip_from_uri: 101%40dev.mtuan.com
variable_sip_from_host: dev.mtuan.com
variable_video_media_flow: disabled
variable_text_media_flow: disabled
variable_channel_name: sofia/internal/101%40dev.mtuan.com
variable_sip_call_id: 36f02684a33547d2bcc4935f79da0571
variable_sip_local_network_addr: 157.119.251.219
variable_sip_network_ip: 157.119.251.207
variable_sip_network_port: 5060
variable_sip_invite_stamp: 1645070976161208
variable_sip_received_ip: 157.119.251.207
variable_sip_received_port: 5060
variable_sip_via_protocol: udp
variable_sip_authorized: true
variable_sip_acl_authed_by: domains
variable_sip_from_user_stripped: 101
variable_sip_from_tag: f5f6e6beb7cf44888c3da5723f9fabf7
variable_sofia_profile_name: internal
variable_sofia_profile_url: sip%3Amod_sofia%40157.119.251.219%3A50061
variable_recovery_profile_name: internal
variable_sip_full_route: %3Csip%3Asbc02.mtuan.com%3Btransport%3Dtcp%3Blr%3E
variable_sip_invite_route_uri: %3Csip%3A157.119.251.207%3Br2%3Don%3Blr%3Bftag%3Df5f6e6beb7cf44888c3da5723f9fabf7%3Bdid%3D811.e31228b2%3E,%3Csip%3A157.119.251.207%3Btransport%3Dtcp%3Br2%3Don%3Blr%3Bftag%3Df5f6e6beb7cf44888c3da5723f9fabf7%3Bdid%3D811.e31228b2%3E
variable_sip_invite_record_route: %3Csip%3A157.119.251.207%3Btransport%3Dtcp%3Br2%3Don%3Blr%3Bftag%3Df5f6e6beb7cf44888c3da5723f9fabf7%3Bdid%3D811.e31228b2%3E,%3Csip%3A157.119.251.207%3Br2%3Don%3Blr%3Bftag%3Df5f6e6beb7cf44888c3da5723f9fabf7%3Bdid%3D811.e31228b2%3E
variable_sip_full_via: SIP/2.0/UDP%20157.119.251.207%3A5060%3Bbranch%3Dz9hG4bK97eb.6e5d7b06.0%3Bi%3D5ef95c71,SIP/2.0/TCP%20192.168.2.19%3A50855%3Breceived%3D113.161.95.53%3Brport%3D53288%3Bbranch%3Dz9hG4bKPj7f4aa5e9ec734a3ca6745470f4a0c0d8%3Balias
variable_sip_recover_via: SIP/2.0/UDP%20157.119.251.207%3A5060%3Bbranch%3Dz9hG4bK97eb.6e5d7b06.0%3Bi%3D5ef95c71,SIP/2.0/TCP%20192.168.2.19%3A50855%3Breceived%3D113.161.95.53%3Brport%3D53288%3Bbranch%3Dz9hG4bKPj7f4aa5e9ec734a3ca6745470f4a0c0d8%3Balias
variable_sip_full_from: %3Csip%3A101%40dev.mtuan.com%3E%3Btag%3Df5f6e6beb7cf44888c3da5723f9fabf7
variable_sip_full_to: %3Csip%3A0965138057%40dev.mtuan.com%3E
variable_sip_allow: PRACK,%20INVITE,%20ACK,%20BYE,%20CANCEL,%20UPDATE,%20INFO,%20SUBSCRIBE,%20NOTIFY,%20REFER,%20MESSAGE,%20OPTIONS
variable_sip_req_params: transport%3Dtcp
variable_sip_req_user: 0965138057
variable_sip_req_uri: 0965138057%40dev.mtuan.com
variable_sip_req_host: dev.mtuan.com
variable_sip_to_user: 0965138057
variable_sip_to_uri: 0965138057%40dev.mtuan.com
variable_sip_to_host: dev.mtuan.com
variable_sip_contact_params: transport%3DTCP%3Bob
variable_sip_contact_user: 101
variable_sip_contact_port: 53288
variable_sip_contact_uri: 101%40113.161.95.53%3A53288
variable_sip_contact_host: 113.161.95.53
variable_sip_user_agent: MicroSIP/3.20.7
variable_sip_via_host: 157.119.251.207
variable_sip_via_port: 5060
variable_max_forwards: 69
variable_presence_id: 101%40dev.mtuan.com
variable_switch_r_sdp: v%3D0%0D%0Ao%3D-%203854084978%203854084978%20IN%20IP4%20192.168.2.19%0D%0As%3Dpjmedia%0D%0Ab%3DAS%3A84%0D%0At%3D0%200%0D%0Aa%3DX-nat%3A0%0D%0Am%3Daudio%204010%20RTP/AVP%200%208%209%2096%2097%2098%2099%20100%204%2018%203%20101%20102%20103%0D%0Ac%3DIN%20IP4%20192.168.2.19%0D%0Ab%3DTIAS%3A64000%0D%0Aa%3Drtpmap%3A0%20PCMU/8000%0D%0Aa%3Drtpmap%3A8%20PCMA/8000%0D%0Aa%3Drtpmap%3A9%20G722/8000%0D%0Aa%3Drtpmap%3A96%20G7221/16000%0D%0Aa%3Dfmtp%3A96%20bitrate%3D24000%0D%0Aa%3Drtpmap%3A97%20G7221/16000%0D%0Aa%3Dfmtp%3A97%20bitrate%3D32000%0D%0Aa%3Drtpmap%3A98%20G7221/32000%0D%0Aa%3Dfmtp%3A98%20bitrate%3D48000%0D%0Aa%3Drtpmap%3A99%20G7221/32000%0D%0Aa%3Dfmtp%3A99%20bitrate%3D24000%0D%0Aa%3Drtpmap%3A100%20G7221/32000%0D%0Aa%3Dfmtp%3A100%20bitrate%3D32000%0D%0Aa%3Drtpmap%3A4%20G723/8000%0D%0Aa%3Drtpmap%3A18%20G729/8000%0D%0Aa%3Drtpmap%3A3%20GSM/8000%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-16%0D%0Aa%3Drtpmap%3A102%20telephone-event/16000%0D%0Aa%3Dfmtp%3A102%200-16%0D%0Aa%3Drtpmap%3A103%20telephone-event/32000%0D%0Aa%3Dfmtp%3A103%200-16%0D%0Aa%3Drtcp%3A4011%20IN%20IP4%20192.168.2.19%0D%0Aa%3Dssrc%3A631720330%20cname%3A785b5ee55308074c%0D%0A
variable_ep_codec_string: CORE_PCM_MODULE.PCMU%408000h%4020i%4064000b,CORE_PCM_MODULE.PCMA%408000h%4020i%4064000b
variable_rtp_use_codec_string: PCMU,PCMA,G711
variable_remote_video_media_flow: inactive
variable_remote_text_media_flow: inactive
variable_remote_audio_media_flow: sendrecv
variable_audio_media_flow: sendrecv
variable_rtp_remote_audio_rtcp_port: 4011
variable_remote_media_ip: 192.168.2.19
variable_remote_media_port: 4010
variable_rtp_audio_recv_pt: 0
variable_rtp_use_codec_name: PCMU
variable_rtp_use_codec_rate: 8000
variable_rtp_use_codec_ptime: 20
variable_rtp_use_codec_channels: 1
variable_rtp_last_audio_codec_string: PCMU%408000h%4020i%401c
variable_read_codec: PCMU
variable_original_read_codec: PCMU
variable_read_rate: 8000
variable_original_read_rate: 8000
variable_write_codec: PCMU
variable_write_rate: 8000
variable_dtmf_type: rfc2833
variable_endpoint_disposition: RECEIVED
variable_call_uuid: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
Hunt-Direction: inbound
Hunt-Logical-Direction: inbound
Hunt-Username: 101
Hunt-Dialplan: XML
Hunt-Caller-ID-Name: 101
Hunt-Caller-ID-Number: 101
Hunt-Orig-Caller-ID-Name: 101
Hunt-Orig-Caller-ID-Number: 101
Hunt-Network-Addr: 157.119.251.207
Hunt-ANI: 101
Hunt-Destination-Number: 0965138057
Hunt-Unique-ID: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
Hunt-Source: mod_sofia
Hunt-Context: public
Hunt-Channel-Name: sofia/internal/101%40dev.mtuan.com
Hunt-Profile-Index: 1
Hunt-Profile-Created-Time: 1645070976161208
Hunt-Channel-Created-Time: 1645070976161208
Hunt-Channel-Answered-Time: 0
Hunt-Channel-Progress-Time: 0
Hunt-Channel-Progress-Media-Time: 0
Hunt-Channel-Hangup-Time: 0
Hunt-Channel-Transfer-Time: 0
Hunt-Channel-Resurrect-Time: 0
Hunt-Channel-Bridged-Time: 0
Hunt-Channel-Last-Hold: 0
Hunt-Channel-Hold-Accum: 0
Hunt-Screen-Bit: true
Hunt-Privacy-Hide-Name: false
Hunt-Privacy-Hide-Number: false


2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Section: dialplan
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Tag Name:
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Key Name:
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Key Value:
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [dialplan] SQL: select dialplan_xml from v_dialplans as p where p.dialplan_context = :call_context and (p.hostname = :hostname or p.hostname is null) and p.dialplan_enabled = 'true' order by p.dialplan_order asc ; params:{"hostname":"cluster-fs","call_context":"public"}
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler] dialplan:public stored in the cache
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler] dialplan:public source: database
Dialplan: sofia/internal/101@dev.mtuan.com parsing [public->From_SBC] continue=false
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [From_SBC] network_addr(157.119.251.207) =~ /157.119.251.207/ break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com Action export(call_direction=inbound) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com export(call_direction=inbound)
2022-02-17 11:09:36.181196 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/internal/101@dev.mtuan.com Action set(domain_name=${sip_to_host})
Dialplan: sofia/internal/101@dev.mtuan.com Action set(context=${sip_to_host})
Dialplan: sofia/internal/101@dev.mtuan.com Action set(call_direction=)
Dialplan: sofia/internal/101@dev.mtuan.com Action set(caller_destination=)
Dialplan: sofia/internal/101@dev.mtuan.com Action transfer(${destination_number} XML ${sip_to_host})
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:287 (sofia/internal/101@dev.mtuan.com) State Change CS_ROUTING -> CS_EXECUTE
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/101@dev.mtuan.com) State ROUTING going to sleep
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/101@dev.mtuan.com) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/101@dev.mtuan.com) State EXECUTE
2022-02-17 11:09:36.181196 [DEBUG] mod_sofia.c:209 sofia/internal/101@dev.mtuan.com SOFIA EXECUTE
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:329 sofia/internal/101@dev.mtuan.com Standard EXECUTE
2022-02-17 11:09:36.181196 [CONSOLE] sofia_presence.c:1619 Event Thread Started
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(domain_name=dev.mtuan.com)
2022-02-17 11:09:36.181196 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [domain_name]=[dev.mtuan.com]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(context=dev.mtuan.com)
2022-02-17 11:09:36.181196 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [context]=[dev.mtuan.com]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(call_direction=)
2022-02-17 11:09:36.181196 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [call_direction]=[UNDEF]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(caller_destination=)
2022-02-17 11:09:36.181196 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [caller_destination]=[UNDEF]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com transfer(0965138057 XML dev.mtuan.com)
2022-02-17 11:09:36.181196 [DEBUG] switch_ivr.c:2250 (sofia/internal/101@dev.mtuan.com) State Change CS_EXECUTE -> CS_ROUTING
2022-02-17 11:09:36.181196 [NOTICE] switch_ivr.c:2257 Transfer sofia/internal/101@dev.mtuan.com to XML[0965138057@dev.mtuan.com]
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/101@dev.mtuan.com) State EXECUTE going to sleep
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/101@dev.mtuan.com) Running State Change CS_ROUTING (Cur 1 Tot 1)
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/101@dev.mtuan.com) State ROUTING
2022-02-17 11:09:36.181196 [DEBUG] mod_sofia.c:145 Call appears to be already acknowledged
2022-02-17 11:09:36.181196 [DEBUG] mod_sofia.c:154 sofia/internal/101@dev.mtuan.com SOFIA ROUTING
2022-02-17 11:09:36.181196 [DEBUG] switch_core_state_machine.c:236 sofia/internal/101@dev.mtuan.com Standard ROUTING
2022-02-17 11:09:36.181196 [INFO] mod_dialplan_xml.c:637 Processing 101 <101>->0965138057 in context dev.mtuan.com
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler]/usr/local/freeswitch/scripts/app/xml_handler/index.lua
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 TuanTuanTuan [xml_handler] Params:
Event-Name: REQUEST_PARAMS
Core-UUID: 96e24b75-0f60-42cb-a86e-d163d5e68acd
FreeSWITCH-Hostname: fs-node-01
FreeSWITCH-Switchname: cluster-fs
FreeSWITCH-IPv4: 157.119.251.219
FreeSWITCH-IPv6: %3A%3A1
Event-Date-Local: 2022-02-17%2011%3A09%3A36
Event-Date-GMT: Thu,%2017%20Feb%202022%2004%3A09%3A36%20GMT
Event-Date-Timestamp: 1645070976181196
Event-Calling-File: mod_dialplan_xml.c
Event-Calling-Function: dialplan_xml_locate
Event-Calling-Line-Number: 608
Event-Sequence: 670
Channel-State: CS_ROUTING
Channel-Call-State: RINGING
Channel-State-Number: 2
Channel-Name: sofia/internal/101%40dev.mtuan.com
Unique-ID: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
Call-Direction: inbound
Presence-Call-Direction: inbound
Channel-HIT-Dialplan: true
Channel-Presence-ID: 101%40dev.mtuan.com
Channel-Call-UUID: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
Answer-State: ringing
Channel-Read-Codec-Name: PCMU
Channel-Read-Codec-Rate: 8000
Channel-Read-Codec-Bit-Rate: 64000
Channel-Write-Codec-Name: PCMU
Channel-Write-Codec-Rate: 8000
Channel-Write-Codec-Bit-Rate: 64000
Caller-Direction: inbound
Caller-Logical-Direction: inbound
Caller-Username: 101
Caller-Dialplan: XML
Caller-Caller-ID-Name: 101
Caller-Caller-ID-Number: 101
Caller-Orig-Caller-ID-Name: 101
Caller-Orig-Caller-ID-Number: 101
Caller-Network-Addr: 157.119.251.207
Caller-ANI: 101
Caller-Destination-Number: 0965138057
Caller-Unique-ID: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
Caller-Source: mod_sofia
Caller-Transfer-Source: 1645070976%3Af3b78878-1e33-4903-81fd-3a8f98991e54%3Abl_xfer%3A0965138057/dev.mtuan.com/XML
Caller-Context: dev.mtuan.com
Caller-RDNIS: 0965138057
Caller-Channel-Name: sofia/internal/101%40dev.mtuan.com
Caller-Profile-Index: 2
Caller-Profile-Created-Time: 1645070976181196
Caller-Channel-Created-Time: 1645070976161208
Caller-Channel-Answered-Time: 0
Caller-Channel-Progress-Time: 0
Caller-Channel-Progress-Media-Time: 0
Caller-Channel-Hangup-Time: 0
Caller-Channel-Transfer-Time: 0
Caller-Channel-Resurrect-Time: 0
Caller-Channel-Bridged-Time: 0
Caller-Channel-Last-Hold: 0
Caller-Channel-Hold-Accum: 0
Caller-Screen-Bit: true
Caller-Privacy-Hide-Name: false
Caller-Privacy-Hide-Number: false
variable_direction: inbound
variable_uuid: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
variable_session_id: 1
variable_sip_from_user: 101
variable_sip_from_uri: 101%40dev.mtuan.com
variable_sip_from_host: dev.mtuan.com
variable_video_media_flow: disabled
variable_text_media_flow: disabled
variable_channel_name: sofia/internal/101%40dev.mtuan.com
variable_sip_call_id: 36f02684a33547d2bcc4935f79da0571
variable_sip_local_network_addr: 157.119.251.219
variable_sip_network_ip: 157.119.251.207
variable_sip_network_port: 5060
variable_sip_invite_stamp: 1645070976161208
variable_sip_received_ip: 157.119.251.207
variable_sip_received_port: 5060
variable_sip_via_protocol: udp
variable_sip_authorized: true
variable_sip_acl_authed_by: domains
variable_sip_from_user_stripped: 101
variable_sip_from_tag: f5f6e6beb7cf44888c3da5723f9fabf7
variable_sofia_profile_name: internal
variable_sofia_profile_url: sip%3Amod_sofia%40157.119.251.219%3A50061
variable_recovery_profile_name: internal
variable_sip_full_route: %3Csip%3Asbc02.mtuan.com%3Btransport%3Dtcp%3Blr%3E
variable_sip_invite_route_uri: %3Csip%3A157.119.251.207%3Br2%3Don%3Blr%3Bftag%3Df5f6e6beb7cf44888c3da5723f9fabf7%3Bdid%3D811.e31228b2%3E,%3Csip%3A157.119.251.207%3Btransport%3Dtcp%3Br2%3Don%3Blr%3Bftag%3Df5f6e6beb7cf44888c3da5723f9fabf7%3Bdid%3D811.e31228b2%3E
variable_sip_invite_record_route: %3Csip%3A157.119.251.207%3Btransport%3Dtcp%3Br2%3Don%3Blr%3Bftag%3Df5f6e6beb7cf44888c3da5723f9fabf7%3Bdid%3D811.e31228b2%3E,%3Csip%3A157.119.251.207%3Br2%3Don%3Blr%3Bftag%3Df5f6e6beb7cf44888c3da5723f9fabf7%3Bdid%3D811.e31228b2%3E
variable_sip_full_via: SIP/2.0/UDP%20157.119.251.207%3A5060%3Bbranch%3Dz9hG4bK97eb.6e5d7b06.0%3Bi%3D5ef95c71,SIP/2.0/TCP%20192.168.2.19%3A50855%3Breceived%3D113.161.95.53%3Brport%3D53288%3Bbranch%3Dz9hG4bKPj7f4aa5e9ec734a3ca6745470f4a0c0d8%3Balias
variable_sip_recover_via: SIP/2.0/UDP%20157.119.251.207%3A5060%3Bbranch%3Dz9hG4bK97eb.6e5d7b06.0%3Bi%3D5ef95c71,SIP/2.0/TCP%20192.168.2.19%3A50855%3Breceived%3D113.161.95.53%3Brport%3D53288%3Bbranch%3Dz9hG4bKPj7f4aa5e9ec734a3ca6745470f4a0c0d8%3Balias
variable_sip_full_from: %3Csip%3A101%40dev.mtuan.com%3E%3Btag%3Df5f6e6beb7cf44888c3da5723f9fabf7
variable_sip_full_to: %3Csip%3A0965138057%40dev.mtuan.com%3E
variable_sip_allow: PRACK,%20INVITE,%20ACK,%20BYE,%20CANCEL,%20UPDATE,%20INFO,%20SUBSCRIBE,%20NOTIFY,%20REFER,%20MESSAGE,%20OPTIONS
variable_sip_req_params: transport%3Dtcp
variable_sip_req_user: 0965138057
variable_sip_req_uri: 0965138057%40dev.mtuan.com
variable_sip_req_host: dev.mtuan.com
variable_sip_to_user: 0965138057
variable_sip_to_uri: 0965138057%40dev.mtuan.com
variable_sip_to_host: dev.mtuan.com
variable_sip_contact_params: transport%3DTCP%3Bob
variable_sip_contact_user: 101
variable_sip_contact_port: 53288
variable_sip_contact_uri: 101%40113.161.95.53%3A53288
variable_sip_contact_host: 113.161.95.53
variable_sip_user_agent: MicroSIP/3.20.7
variable_sip_via_host: 157.119.251.207
variable_sip_via_port: 5060
variable_presence_id: 101%40dev.mtuan.com
variable_switch_r_sdp: v%3D0%0D%0Ao%3D-%203854084978%203854084978%20IN%20IP4%20192.168.2.19%0D%0As%3Dpjmedia%0D%0Ab%3DAS%3A84%0D%0At%3D0%200%0D%0Aa%3DX-nat%3A0%0D%0Am%3Daudio%204010%20RTP/AVP%200%208%209%2096%2097%2098%2099%20100%204%2018%203%20101%20102%20103%0D%0Ac%3DIN%20IP4%20192.168.2.19%0D%0Ab%3DTIAS%3A64000%0D%0Aa%3Drtpmap%3A0%20PCMU/8000%0D%0Aa%3Drtpmap%3A8%20PCMA/8000%0D%0Aa%3Drtpmap%3A9%20G722/8000%0D%0Aa%3Drtpmap%3A96%20G7221/16000%0D%0Aa%3Dfmtp%3A96%20bitrate%3D24000%0D%0Aa%3Drtpmap%3A97%20G7221/16000%0D%0Aa%3Dfmtp%3A97%20bitrate%3D32000%0D%0Aa%3Drtpmap%3A98%20G7221/32000%0D%0Aa%3Dfmtp%3A98%20bitrate%3D48000%0D%0Aa%3Drtpmap%3A99%20G7221/32000%0D%0Aa%3Dfmtp%3A99%20bitrate%3D24000%0D%0Aa%3Drtpmap%3A100%20G7221/32000%0D%0Aa%3Dfmtp%3A100%20bitrate%3D32000%0D%0Aa%3Drtpmap%3A4%20G723/8000%0D%0Aa%3Drtpmap%3A18%20G729/8000%0D%0Aa%3Drtpmap%3A3%20GSM/8000%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-16%0D%0Aa%3Drtpmap%3A102%20telephone-event/16000%0D%0Aa%3Dfmtp%3A102%200-16%0D%0Aa%3Drtpmap%3A103%20telephone-event/32000%0D%0Aa%3Dfmtp%3A103%200-16%0D%0Aa%3Drtcp%3A4011%20IN%20IP4%20192.168.2.19%0D%0Aa%3Dssrc%3A631720330%20cname%3A785b5ee55308074c%0D%0A
variable_ep_codec_string: CORE_PCM_MODULE.PCMU%408000h%4020i%4064000b,CORE_PCM_MODULE.PCMA%408000h%4020i%4064000b
variable_rtp_use_codec_string: PCMU,PCMA,G711
variable_remote_video_media_flow: inactive
variable_remote_text_media_flow: inactive
variable_remote_audio_media_flow: sendrecv
variable_audio_media_flow: sendrecv
variable_rtp_remote_audio_rtcp_port: 4011
variable_remote_media_ip: 192.168.2.19
variable_remote_media_port: 4010
variable_rtp_audio_recv_pt: 0
variable_rtp_use_codec_name: PCMU
variable_rtp_use_codec_rate: 8000
variable_rtp_use_codec_ptime: 20
variable_rtp_use_codec_channels: 1
variable_rtp_last_audio_codec_string: PCMU%408000h%4020i%401c
variable_read_codec: PCMU
variable_original_read_codec: PCMU
variable_read_rate: 8000
variable_original_read_rate: 8000
variable_write_codec: PCMU
variable_write_rate: 8000
variable_dtmf_type: rfc2833
variable_endpoint_disposition: RECEIVED
variable_export_vars: call_direction
variable_domain_name: dev.mtuan.com
variable_context: dev.mtuan.com
variable_current_application_data: 0965138057%20XML%20dev.mtuan.com
variable_current_application: transfer
variable_max_forwards: 68
variable_transfer_history: 1645070976%3Af3b78878-1e33-4903-81fd-3a8f98991e54%3Abl_xfer%3A0965138057/dev.mtuan.com/XML
variable_transfer_source: 1645070976%3Af3b78878-1e33-4903-81fd-3a8f98991e54%3Abl_xfer%3A0965138057/dev.mtuan.com/XML
variable_call_uuid: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
Hunt-Direction: inbound
Hunt-Logical-Direction: inbound
Hunt-Username: 101
Hunt-Dialplan: XML
Hunt-Caller-ID-Name: 101
Hunt-Caller-ID-Number: 101
Hunt-Orig-Caller-ID-Name: 101
Hunt-Orig-Caller-ID-Number: 101
Hunt-Network-Addr: 157.119.251.207
Hunt-ANI: 101
Hunt-Destination-Number: 0965138057
Hunt-Unique-ID: 8b761da4-a00a-4ab6-9a5a-6146d05bb62e
Hunt-Source: mod_sofia
Hunt-Transfer-Source: 1645070976%3Af3b78878-1e33-4903-81fd-3a8f98991e54%3Abl_xfer%3A0965138057/dev.mtuan.com/XML
Hunt-Context: dev.mtuan.com
Hunt-RDNIS: 0965138057
Hunt-Channel-Name: sofia/internal/101%40dev.mtuan.com
Hunt-Profile-Index: 2
Hunt-Profile-Created-Time: 1645070976181196
Hunt-Channel-Created-Time: 1645070976161208
Hunt-Channel-Answered-Time: 0
Hunt-Channel-Progress-Time: 0
Hunt-Channel-Progress-Media-Time: 0
Hunt-Channel-Hangup-Time: 0
Hunt-Channel-Transfer-Time: 0
Hunt-Channel-Resurrect-Time: 0
Hunt-Channel-Bridged-Time: 0
Hunt-Channel-Last-Hold: 0
Hunt-Channel-Hold-Accum: 0
Hunt-Screen-Bit: true
Hunt-Privacy-Hide-Name: false
Hunt-Privacy-Hide-Number: false


2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Section: dialplan
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Tag Name:
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Key Name:
2022-02-17 11:09:36.181196 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Key Value:
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [dialplan] SQL: select dialplan_xml from v_dialplans as p where (p.dialplan_context = :call_context or p.dialplan_context = '${domain_name}') and (p.hostname = :hostname or p.hostname is null) and p.dialplan_enabled = 'true' order by p.dialplan_order asc ; params:{"hostname":"cluster-fs","call_context":"dev.mtuan.com"}
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] dialplan:dev.mtuan.com stored in the cache
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] dialplan:dev.mtuan.com source: database
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->user_exists] continue=true
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler]/usr/local/freeswitch/scripts/app/xml_handler/index.lua
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 TuanTuanTuan [xml_handler] Params:
Event-Name: REQUEST_PARAMS
Core-UUID: 96e24b75-0f60-42cb-a86e-d163d5e68acd
FreeSWITCH-Hostname: fs-node-01
FreeSWITCH-Switchname: cluster-fs
FreeSWITCH-IPv4: 157.119.251.219
FreeSWITCH-IPv6: %3A%3A1
Event-Date-Local: 2022-02-17%2011%3A09%3A36
Event-Date-GMT: Thu,%2017%20Feb%202022%2004%3A09%3A36%20GMT
Event-Date-Timestamp: 1645070976201183
Event-Calling-File: switch_xml.c
Event-Calling-Function: switch_xml_locate_user
Event-Calling-Line-Number: 2181
Event-Sequence: 676
key: id
user: 0965138057
domain: dev.mtuan.com


2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Section: directory
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Tag Name: domain
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Key Name: name
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Key Value: dev.mtuan.com
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler-directory][memcache] get key: directory:0965138057@dev.mtuan.com fail: NOT FOUND
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] SQL: SELECT domain_uuid FROM v_domains WHERE domain_name = :domain_name ; params:{"domain_name":"dev.mtuan.com"}
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] SQL: SELECT * FROM v_extensions WHERE domain_uuid = :domain_uuid and (extension = :user or number_alias = :user) and enabled = 'true' ; params:{"user":"0965138057","domain_uuid":"1591095e-6c9e-41bb-a646-24f2b6e61197"}
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] XML_STRING:
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="result">
<result status="not found" />
</section>
</document>
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(user_exists=false)
2022-02-17 11:09:36.201183 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [user_exists]=[false]
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->caller-details] continue=true
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Action set(caller_destination=${destination_number}) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(caller_destination=0965138057)
2022-02-17 11:09:36.201183 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [caller_destination]=[0965138057]
Dialplan: sofia/internal/101@dev.mtuan.com Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(caller_id_name=101)
2022-02-17 11:09:36.201183 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [caller_id_name]=[101]
Dialplan: sofia/internal/101@dev.mtuan.com Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->variables] continue=true
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com Action export(origination_callee_id_name=${destination_number})
Dialplan: sofia/internal/101@dev.mtuan.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->call-direction] continue=true
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com ANTI-Action export(call_direction=local) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com export(call_direction=local)
2022-02-17 11:09:36.201183 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[local]
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->call_block] continue=true
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [call_block] ${call_direction}(local) =~ /^inbound$/ break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->user_record] continue=true
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [user_record] () =~ // break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler]/usr/local/freeswitch/scripts/app/xml_handler/index.lua
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 TuanTuanTuan [xml_handler] Params:
Event-Name: REQUEST_PARAMS
Core-UUID: 96e24b75-0f60-42cb-a86e-d163d5e68acd
FreeSWITCH-Hostname: fs-node-01
FreeSWITCH-Switchname: cluster-fs
FreeSWITCH-IPv4: 157.119.251.219
FreeSWITCH-IPv6: %3A%3A1
Event-Date-Local: 2022-02-17%2011%3A09%3A36
Event-Date-GMT: Thu,%2017%20Feb%202022%2004%3A09%3A36%20GMT
Event-Date-Timestamp: 1645070976201183
Event-Calling-File: switch_xml.c
Event-Calling-Function: switch_xml_locate_user
Event-Calling-Line-Number: 2181
Event-Sequence: 690
key: id
user: 101
domain: dev.mtuan.com


2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Section: directory
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Tag Name: domain
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Key Name: name
2022-02-17 11:09:36.201183 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Key Value: dev.mtuan.com
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler-directory][memcache] get key: directory:101@dev.mtuan.com fail: NOT FOUND
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler] SQL: SELECT domain_uuid FROM v_domains WHERE domain_name = :domain_name ; params:{"domain_name":"dev.mtuan.com"}
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler] SQL: SELECT * FROM v_extensions WHERE domain_uuid = :domain_uuid and (extension = :user or number_alias = :user) and enabled = 'true' ; params:{"user":"101","domain_uuid":"1591095e-6c9e-41bb-a646-24f2b6e61197"}
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler] SQL: SELECT * FROM v_voicemails WHERE domain_uuid = :domain_uuid and voicemail_id = :voicemail_id ; params:{"voicemail_id":"101","domain_uuid":"1591095e-6c9e-41bb-a646-24f2b6e61197"}
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler-directory][memcache] set key: directory:101@dev.mtuan.com
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler] directory:101@dev.mtuan.com source: database
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler] XML_STRING:
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="directory">
<domain name="dev.mtuan.com" alias="true">
<params>
<param name="jsonrpc-allowed-methods" value="verto"/>
<param name="jsonrpc-allowed-event-channels" value="demo,conference,presence"/>
</params>
<groups>
<group name="default">
<users>
<user id="101" type=>
<params>
<param name="password" value=".C.L.kxjVP"/>
<param name="vm-enabled" value="true"/>
<param name="dial-string" value="{sip_invite_domain=dev.mtuan.com,presence_id=101@dev.mtuan.com}${sofia_contact(101@dev.mtuan.com)}"/>
<param name="verto-context" value="dev.mtuan.com"/>
<param name="verto-dialplan" value="XML"/>
<param name="jsonrpc-allowed-methods" value="verto"/>
<param name="jsonrpc-allowed-event-channels" value="demo,conference,presence"/>
</params>
<variables>
<variable name="domain_uuid" value="1591095e-6c9e-41bb-a646-24f2b6e61197"/>
<variable name="domain_name" value="dev.mtuan.com"/>
<variable name="extension_uuid" value="5cc073ab-96ff-40dc-be40-f9f01f7ad251"/>
<variable name="call_timeout" value="30"/>
<variable name="caller_id_name" value="101"/>
<variable name="caller_id_number" value="101"/>
<variable name="presence_id" value="101@dev.mtuan.com"/>
<variable name="call_screen_enabled" value="false"/>
<variable name="user_record" value="all"/>
<variable name="user_context" value="dev.mtuan.com"/>
<variable name="directory-visible" value="true"/>
<variable name="directory-exten-visible" value="true"/>
<variable name="limit_max" value="5"/>
<variable name="limit_destination" value="error/user_busy"/>
<variable name="record_stereo" value="true"/>
<variable name="transfer_fallback_extension" value="operator"/>
<variable name="export_vars" value="domain_name"/>
</variables>
</user>
</users>
</group>
</groups>
</domain>
</section>
</document>
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(from_user_exists=true)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [from_user_exists]=[true]
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler]/usr/local/freeswitch/scripts/app/xml_handler/index.lua
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 TuanTuanTuan [xml_handler] Params:
Event-Name: REQUEST_PARAMS
Core-UUID: 96e24b75-0f60-42cb-a86e-d163d5e68acd
FreeSWITCH-Hostname: fs-node-01
FreeSWITCH-Switchname: cluster-fs
FreeSWITCH-IPv4: 157.119.251.219
FreeSWITCH-IPv6: %3A%3A1
Event-Date-Local: 2022-02-17%2011%3A09%3A36
Event-Date-GMT: Thu,%2017%20Feb%202022%2004%3A09%3A36%20GMT
Event-Date-Timestamp: 1645070976221168
Event-Calling-File: mod_commands.c
Event-Calling-Function: user_data_function
Event-Calling-Line-Number: 1327
Event-Sequence: 701
type: var
key: id
user: 101
domain: dev.mtuan.com


2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Section: directory
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Tag Name: domain
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Key Name: name
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler] Key Value: dev.mtuan.com
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler-directory][memcache] get key: directory:101@dev.mtuan.com pass!
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler] directory:101@dev.mtuan.com source: memcache
2022-02-17 11:09:36.221168 [NOTICE] switch_cpp.cpp:1465 [xml_handler] XML_STRING:
<?xml version="1.0" encoding="UTF-8" standalone="no"?>
<document type="freeswitch/xml">
<section name="directory">
<domain name="dev.mtuan.com" alias="true">
<params>
<param name="jsonrpc-allowed-methods" value="verto"/>
<param name="jsonrpc-allowed-event-channels" value="demo,conference,presence"/>
</params>
<groups>
<group name="default">
<users>
<user id="101" type=>
<params>
<param name="password" value=".C.L.kxjVP"/>
<param name="vm-enabled" value="true"/>
<param name="dial-string" value="{sip_invite_domain=dev.mtuan.com,presence_id=101@dev.mtuan.com}${sofia_contact(101@dev.mtuan.com)}"/>
<param name="verto-context" value="dev.mtuan.com"/>
<param name="verto-dialplan" value="XML"/>
<param name="jsonrpc-allowed-methods" value="verto"/>
<param name="jsonrpc-allowed-event-channels" value="demo,conference,presence"/>
</params>
<variables>
<variable name="domain_uuid" value="1591095e-6c9e-41bb-a646-24f2b6e61197"/>
<variable name="domain_name" value="dev.mtuan.com"/>
<variable name="extension_uuid" value="5cc073ab-96ff-40dc-be40-f9f01f7ad251"/>
<variable name="call_timeout" value="30"/>
<variable name="caller_id_name" value="101"/>
<variable name="caller_id_number" value="101"/>
<variable name="presence_id" value="101@dev.mtuan.com"/>
<variable name="call_screen_enabled" value="false"/>
<variable name="user_record" value="all"/>
<variable name="user_context" value="dev.mtuan.com"/>
<variable name="directory-visible" value="true"/>
<variable name="directory-exten-visible" value="true"/>
<variable name="limit_max" value="5"/>
<variable name="limit_destination" value="error/user_busy"/>
<variable name="record_stereo" value="true"/>
<variable name="transfer_fallback_extension" value="operator"/>
<variable name="export_vars" value="domain_name"/>
</variables>
</user>
</users>
</group>
</groups>
</domain>
</section>
</document>
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(from_user_record=all)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [from_user_record]=[all]
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [user_record] ${from_user_record}(all) =~ /^all$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Action set(record_session=true) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(record_session=true)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [record_session]=[true]
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^inbound$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^outbound$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [user_record] ${from_user_record}(all) =~ /^local$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [user_record] ${record_session}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com Action set(record_path=${recordings_dir}/${domain_name}/archive/${strftime(%Y)}/${strftime(%b)}/${strftime(%d)}) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(record_path=/usr/local/freeswitch/recordings/dev.mtuan.com/archive/2022/Feb/17)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [record_path]=[/usr/local/freeswitch/recordings/dev.mtuan.com/archive/2022/Feb/17]
Dialplan: sofia/internal/101@dev.mtuan.com Action set(record_name=${uuid}.${record_ext}) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(record_name=8b761da4-a00a-4ab6-9a5a-6146d05bb62e.mp3)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [record_name]=[8b761da4-a00a-4ab6-9a5a-6146d05bb62e.mp3]
Dialplan: sofia/internal/101@dev.mtuan.com Action set(recording_follow_transfer=true) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(recording_follow_transfer=true)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [recording_follow_transfer]=[true]
Dialplan: sofia/internal/101@dev.mtuan.com Action set(record_append=true) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(record_append=true)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [record_append]=[true]
Dialplan: sofia/internal/101@dev.mtuan.com Action set(record_in_progress=true) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(record_in_progress=true)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [record_in_progress]=[true]
Dialplan: sofia/internal/101@dev.mtuan.com Action set(${uuid_record ${uuid} start ${record_path}/${record_name}})
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->click_to_call] continue=true
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [click_to_call] ${click_to_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->redial] continue=true
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [redial] destination_number(0965138057) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/internal/101@dev.mtuan.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->speed_dial] continue=false
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [speed_dial] destination_number(0965138057) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->default_caller_id] continue=true
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(emergency_caller_id_name=)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [emergency_caller_id_name]=[UNDEF]
Dialplan: sofia/internal/101@dev.mtuan.com Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(emergency_caller_id_number=)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [emergency_caller_id_number]=[UNDEF]
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [default_caller_id] ${outbound_caller_id_number}() =~ /^$/ break=never
Dialplan: sofia/internal/101@dev.mtuan.com Action set(outbound_caller_id_name=${default_outbound_caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(outbound_caller_id_name=)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [outbound_caller_id_name]=[UNDEF]
Dialplan: sofia/internal/101@dev.mtuan.com Action set(outbound_caller_id_number=${default_outbound_caller_id_number}) INLINE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(outbound_caller_id_number=)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [outbound_caller_id_number]=[UNDEF]
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->blacklist_check] continue=true
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [blacklist_check] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com Action set(blacklist_result=${blacklist(check blocked ${destination_number})})
Dialplan: sofia/internal/101@dev.mtuan.com Regex (FAIL) [blacklist_check] ${blacklist_result}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com parsing [dev.mtuan.com->pitel01.mtuan.com.d1011] continue=false
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [pitel01.mtuan.com.d1011] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com Regex (PASS) [pitel01.mtuan.com.d1011] destination_number(0965138057) =~ /^(\d{10,11})$/ break=on-false
Dialplan: sofia/internal/101@dev.mtuan.com Action set(sip_h_X-accountcode=${accountcode})
Dialplan: sofia/internal/101@dev.mtuan.com Action export(call_direction=outbound)
Dialplan: sofia/internal/101@dev.mtuan.com Action unset(call_timeout)
Dialplan: sofia/internal/101@dev.mtuan.com Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/101@dev.mtuan.com Action set(effective_caller_id_name=02836220678)
Dialplan: sofia/internal/101@dev.mtuan.com Action set(effective_caller_id_number=02836220678)
Dialplan: sofia/internal/101@dev.mtuan.com Action set(inherit_codec=true)
Dialplan: sofia/internal/101@dev.mtuan.com Action set(ignore_display_updates=true)
Dialplan: sofia/internal/101@dev.mtuan.com Action set(callee_id_number=0965138057)
Dialplan: sofia/internal/101@dev.mtuan.com Action set(continue_on_fail=true)
Dialplan: sofia/internal/101@dev.mtuan.com Action bridge(sofia/gateway/1b3ae70f-2bfe-4549-b8a4-7986c85075c3/0965138057)
2022-02-17 11:09:36.221168 [DEBUG] switch_core_state_machine.c:287 (sofia/internal/101@dev.mtuan.com) State Change CS_ROUTING -> CS_EXECUTE
2022-02-17 11:09:36.221168 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/101@dev.mtuan.com) State ROUTING going to sleep
2022-02-17 11:09:36.221168 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/101@dev.mtuan.com) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2022-02-17 11:09:36.221168 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/101@dev.mtuan.com) State EXECUTE
2022-02-17 11:09:36.221168 [DEBUG] mod_sofia.c:209 sofia/internal/101@dev.mtuan.com SOFIA EXECUTE
2022-02-17 11:09:36.221168 [DEBUG] switch_core_state_machine.c:329 sofia/internal/101@dev.mtuan.com Standard EXECUTE
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(caller_id_number=101)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [caller_id_number]=[101]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com export(origination_callee_id_name=0965138057)
2022-02-17 11:09:36.221168 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [origination_callee_id_name]=[0965138057]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(RFC2822_DATE=Thu, 17 Feb 2022 11:09:36 +0700)
2022-02-17 11:09:36.221168 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [RFC2822_DATE]=[Thu, 17 Feb 2022 11:09:36 +0700]
2022-02-17 11:09:36.221168 [INFO] switch_ivr_async.c:2855 Sending early media
2022-02-17 11:09:36.221168 [DEBUG] switch_core_media.c:8675 AUDIO RTP [sofia/internal/101@dev.mtuan.com] 157.119.251.219 port 16532 -> 192.168.2.19 port 4010 codec: 0 ms: 20
2022-02-17 11:09:36.221168 [DEBUG] switch_rtp.c:4478 Starting timer [soft] 160 bytes per 20ms
2022-02-17 11:09:36.241169 [DEBUG] switch_core_media.c:8897 Activating RTCP PORT 4011
2022-02-17 11:09:36.241169 [DEBUG] switch_rtp.c:4876 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 4011
2022-02-17 11:09:36.241169 [DEBUG] switch_rtp.c:2638 Setting RTCP remote addr to 192.168.2.19:4011 2
2022-02-17 11:09:36.241169 [DEBUG] switch_core_media.c:8989 sofia/internal/101@dev.mtuan.com Set 2833 dtmf send payload to 101
2022-02-17 11:09:36.241169 [DEBUG] switch_core_media.c:8996 sofia/internal/101@dev.mtuan.com Set 2833 dtmf receive payload to 101
2022-02-17 11:09:36.241169 [DEBUG] switch_core_media.c:9019 sofia/internal/101@dev.mtuan.com Set rtp dtmf delay to 40
2022-02-17 11:09:36.241169 [DEBUG] mod_sofia.c:2593 Ring SDP:
v=0
o=FreeSWITCH 1645054444 1645054445 IN IP4 157.119.251.219
s=FreeSWITCH
c=IN IP4 157.119.251.219
t=0 0
m=audio 16532 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
a=rtcp:16533 IN IP4 157.119.251.219

2022-02-17 11:09:36.241169 [NOTICE] mod_sofia.c:2596 Pre-Answer sofia/internal/101@dev.mtuan.com!
2022-02-17 11:09:36.241169 [DEBUG] switch_channel.c:3565 (sofia/internal/101@dev.mtuan.com) Callstate Change RINGING -> EARLY
2022-02-17 11:09:36.261172 [DEBUG] sofia.c:7406 Channel sofia/internal/101@dev.mtuan.com entering state [early][183]
2022-02-17 11:09:36.261172 [DEBUG] switch_ivr_async.c:1427 Record session sample rate: 8000 -> 8000
2022-02-17 11:09:36.261172 [DEBUG] switch_core_media_bug.c:970 Attaching BUG to sofia/internal/101@dev.mtuan.com
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(+OK Success
)
2022-02-17 11:09:36.261172 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [+OK Success
]=[UNDEF]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com hash(insert/dev.mtuan.com-last_dial/101/0965138057)
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(blacklist_result=true)
2022-02-17 11:09:36.261172 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [blacklist_result]=[true]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(sip_h_X-accountcode=)
2022-02-17 11:09:36.261172 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [sip_h_X-accountcode]=[UNDEF]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com export(call_direction=outbound)
2022-02-17 11:09:36.261172 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[outbound]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com unset(call_timeout)
2022-02-17 11:09:36.261172 [DEBUG] mod_dptools.c:1830 UNSET [call_timeout]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(hangup_after_bridge=true)
2022-02-17 11:09:36.261172 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(effective_caller_id_name=02836220678)
2022-02-17 11:09:36.261172 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [effective_caller_id_name]=[02836220678]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(effective_caller_id_number=02836220678)
2022-02-17 11:09:36.261172 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [effective_caller_id_number]=[02836220678]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(inherit_codec=true)
2022-02-17 11:09:36.261172 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [inherit_codec]=[true]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(ignore_display_updates=true)
2022-02-17 11:09:36.261172 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [ignore_display_updates]=[true]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(callee_id_number=0965138057)
2022-02-17 11:09:36.261172 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [callee_id_number]=[0965138057]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com set(continue_on_fail=true)
2022-02-17 11:09:36.261172 [DEBUG] mod_dptools.c:1685 SET sofia/internal/101@dev.mtuan.com [continue_on_fail]=[true]
EXECUTE [depth=0] sofia/internal/101@dev.mtuan.com bridge(sofia/gateway/1b3ae70f-2bfe-4549-b8a4-7986c85075c3/0965138057)
2022-02-17 11:09:36.261172 [DEBUG] switch_channel.c:1264 sofia/internal/101@dev.mtuan.com EXPORTING[export_vars] [call_direction]=[outbound] to event
2022-02-17 11:09:36.261172 [DEBUG] switch_channel.c:1264 sofia/internal/101@dev.mtuan.com EXPORTING[export_vars] [call_direction]=[outbound] to event
2022-02-17 11:09:36.261172 [DEBUG] switch_channel.c:1264 sofia/internal/101@dev.mtuan.com EXPORTING[export_vars] [origination_callee_id_name]=[0965138057] to event
2022-02-17 11:09:36.261172 [DEBUG] switch_channel.c:1264 sofia/internal/101@dev.mtuan.com EXPORTING[export_vars] [call_direction]=[outbound] to event
2022-02-17 11:09:36.261172 [DEBUG] switch_ivr_originate.c:2272 Parsing global variables
2022-02-17 11:09:36.261172 [NOTICE] switch_channel.c:1118 New Channel sofia/external/0965138057 [37bdb9dc-37a7-4c10-88c8-d1e8035d4a19]
2022-02-17 11:09:36.261172 [DEBUG] mod_sofia.c:5102 (sofia/external/0965138057) State Change CS_NEW -> CS_INIT
2022-02-17 11:09:36.261172 [DEBUG] switch_core_state_machine.c:585 (sofia/external/0965138057) Running State Change CS_INIT (Cur 2 Tot 2)
2022-02-17 11:09:36.261172 [DEBUG] switch_core_state_machine.c:628 (sofia/external/0965138057) State INIT
2022-02-17 11:09:36.261172 [DEBUG] mod_sofia.c:93 sofia/external/0965138057 SOFIA INIT
2022-02-17 11:09:36.261172 [INFO] sofia_glue.c:1621 sofia/external/0965138057 sending invite call-id: (null)
2022-02-17 11:09:36.261172 [DEBUG] sofia_glue.c:1624 sofia/external/0965138057 sending invite version: 1.10.6-release git 1ff9d0a 2021-03-25 13:16:09Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1645042762 1645042763 IN IP4 157.119.251.219
s=FreeSWITCH
c=IN IP4 157.119.251.219
t=0 0
m=audio 28214 RTP/AVP 0 8 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2022-02-17 11:09:36.261172 [DEBUG] switch_core_state_machine.c:40 sofia/external/0965138057 Standard INIT
2022-02-17 11:09:36.261172 [DEBUG] switch_core_state_machine.c:48 (sofia/external/0965138057) State Change CS_INIT -> CS_ROUTING
2022-02-17 11:09:36.261172 [DEBUG] switch_core_state_machine.c:628 (sofia/external/0965138057) State INIT going to sleep
2022-02-17 11:09:36.261172 [DEBUG] switch_core_state_machine.c:585 (sofia/external/0965138057) Running State Change CS_ROUTING (Cur 2 Tot 2)
2022-02-17 11:09:36.261172 [DEBUG] switch_core_state_machine.c:644 (sofia/external/0965138057) State ROUTING
2022-02-17 11:09:36.261172 [DEBUG] mod_sofia.c:154 sofia/external/0965138057 SOFIA ROUTING
2022-02-17 11:09:36.261172 [DEBUG] switch_ivr_originate.c:67 (sofia/external/0965138057) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-02-17 11:09:36.261172 [DEBUG] switch_core_state_machine.c:644 (sofia/external/0965138057) State ROUTING going to sleep
2022-02-17 11:09:36.261172 [DEBUG] switch_core_state_machine.c:585 (sofia/external/0965138057) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 2)
2022-02-17 11:09:36.261172 [DEBUG] switch_core_state_machine.c:663 (sofia/external/0965138057) State CONSUME_MEDIA
2022-02-17 11:09:36.261172 [DEBUG] switch_core_state_machine.c:663 (sofia/external/0965138057) State CONSUME_MEDIA going to sleep
2022-02-17 11:09:36.261172 [DEBUG] sofia.c:7406 Channel sofia/external/0965138057 entering state [calling][0]
2022-02-17 11:09:36.261172 [INFO] switch_rtp.c:7170 Auto Changing audio RTCP port from 192.168.2.19:4011 to 113.161.95.53:39212
2022-02-17 11:09:36.261172 [DEBUG] switch_rtp.c:2638 Setting RTCP remote addr to 113.161.95.53:39212 2
2022-02-17 11:09:36.261172 [DEBUG] switch_ivr_async.c:1717 No silence detection configured; assuming start of speech
2022-02-17 11:09:36.281202 [DEBUG] switch_core_io.c:448 Setting BUG Codec PCMU:0
2022-02-17 11:09:36.301202 [DEBUG] switch_rtp.c:1923 rtcp_stats_init: audio ssrc[631720330] base_seq[26537]
2022-02-17 11:09:36.461214 [INFO] switch_rtp.c:7753 Auto Changing audio port from 192.168.2.19:4010 to 113.161.95.53:39211
2022-02-17 11:09:37.281181 [INFO] sofia.c:1370 sofia/external/0965138057 Update Callee ID to "0965138057" <sip:0965138057@pitel01.mtuan.com>
2022-02-17 11:09:37.281181 [DEBUG] sofia.c:7406 Channel sofia/external/0965138057 entering state [proceeding][183]
2022-02-17 11:09:37.281181 [DEBUG] sofia.c:7416 Remote SDP:
v=0
o=FreeSWITCH 1645053277 1645053278 IN IP4 27.71.234.186
s=FreeSWITCH
c=IN IP4 27.71.234.186
t=0 0
m=audio 17700 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=rtcp:17701 IN IP4 27.71.234.186

2022-02-17 11:09:37.281181 [NOTICE] sofia.c:7419 Pre-Answer sofia/external/0965138057!
2022-02-17 11:09:37.281181 [DEBUG] switch_channel.c:3565 (sofia/external/0965138057) Callstate Change DOWN -> EARLY
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:5656 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:5601 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:5517 Set telephone-event payload to 101@8000
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:3847 Set Codec sofia/external/0965138057 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2022-02-17 11:09:37.281181 [DEBUG] switch_core_codec.c:111 sofia/external/0965138057 Original read codec set to PCMU:0
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:5860 Set telephone-event payload to 101@8000
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:5918 sofia/external/0965138057 Set 2833 dtmf send payload to 101 recv payload to 101
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:8675 AUDIO RTP [sofia/external/0965138057] 157.119.251.219 port 28214 -> 27.71.234.186 port 17700 codec: 0 ms: 20
2022-02-17 11:09:37.281181 [DEBUG] switch_rtp.c:4478 Starting timer [soft] 160 bytes per 20ms
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:8897 Activating RTCP PORT 17701
2022-02-17 11:09:37.281181 [DEBUG] switch_rtp.c:4876 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 17701
2022-02-17 11:09:37.281181 [DEBUG] switch_rtp.c:2638 Setting RTCP remote addr to 27.71.234.186:17701 2
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:8989 sofia/external/0965138057 Set 2833 dtmf send payload to 101
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:8996 sofia/external/0965138057 Set 2833 dtmf receive payload to 101
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:9019 sofia/external/0965138057 Set rtp dtmf delay to 40
2022-02-17 11:09:37.281181 [DEBUG] switch_core_media.c:9025 Set comfort noise payload to 13
2022-02-17 11:09:37.281181 [DEBUG] switch_ivr_originate.c:3883 Originate Resulted in Success: [sofia/external/0965138057]
2022-02-17 11:09:37.281181 [DEBUG] switch_ivr_bridge.c:1793 (sofia/external/0965138057) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2022-02-17 11:09:37.301175 [DEBUG] switch_core_state_machine.c:585 (sofia/external/0965138057) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 2)
2022-02-17 11:09:37.301175 [DEBUG] switch_core_state_machine.c:654 (sofia/external/0965138057) State EXCHANGE_MEDIA
2022-02-17 11:09:37.301175 [DEBUG] mod_sofia.c:656 SOFIA EXCHANGE_MEDIA
2022-02-17 11:09:37.401208 [DEBUG] switch_rtp.c:1923 rtcp_stats_init: audio ssrc[3458599272] base_seq[12710]
2022-02-17 11:09:37.421208 [DEBUG] switch_rtp.c:7793 Correct audio ip/port confirmed.
2022-02-17 11:09:40.841210 [INFO] mod_shout.c:332 LAME 3.99.5 64bits (http://lame.sf.net)
2022-02-17 11:09:40.841210 [INFO] mod_shout.c:332 polyphase lowpass filter disabled
2022-02-17 11:09:41.301174 [DEBUG] switch_rtp.c:7191 Correct audio RTCP ip/port confirmed.
freeswitch@cluster-fs>
freeswitch@cluster-fs>
freeswitch@cluster-fs>
freeswitch@cluster-fs>
freeswitch@cluster-fs>
2022-02-17 11:09:47.281215 [INFO] sofia.c:1370 sofia/external/0965138057 Update Callee ID to "0965138057" <sip:0965138057@pitel01.mtuan.com>
2022-02-17 11:09:47.281215 [DEBUG] sofia.c:7406 Channel sofia/external/0965138057 entering state [completing][200]
2022-02-17 11:09:47.281215 [DEBUG] sofia.c:7413 Duplicate SDP
v=0
o=FreeSWITCH 1645053277 1645053278 IN IP4 27.71.234.186
s=FreeSWITCH
c=IN IP4 27.71.234.186
t=0 0
m=audio 17700 RTP/AVP 0 101 13
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=rtcp:17701 IN IP4 27.71.234.186

2022-02-17 11:09:47.301203 [DEBUG] sofia.c:7406 Channel sofia/external/0965138057 entering state [ready][200]
2022-02-17 11:09:47.301203 [NOTICE] sofia.c:8527 Channel [sofia/external/0965138057] has been answered
2022-02-17 11:09:47.301203 [DEBUG] switch_channel.c:3865 (sofia/external/0965138057) Callstate Change EARLY -> ACTIVE
2022-02-17 11:09:47.321171 [DEBUG] switch_core_media.c:8657 Audio params are unchanged for sofia/internal/101@dev.mtuan.com.
2022-02-17 11:09:47.321171 [DEBUG] mod_sofia.c:898 Local SDP sofia/internal/101@dev.mtuan.com:
v=0
o=FreeSWITCH 1645054444 1645054446 IN IP4 157.119.251.219
s=FreeSWITCH
c=IN IP4 157.119.251.219
t=0 0
m=audio 16532 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
a=rtcp:16533 IN IP4 157.119.251.219

2022-02-17 11:09:47.321171 [NOTICE] switch_ivr_bridge.c:731 Channel [sofia/internal/101@dev.mtuan.com] has been answered
2022-02-17 11:09:47.321171 [DEBUG] switch_channel.c:3865 (sofia/internal/101@dev.mtuan.com) Callstate Change EARLY -> ACTIVE
2022-02-17 11:09:47.321171 [DEBUG] sofia.c:7406 Channel sofia/internal/101@dev.mtuan.com entering state [completed][200]
2022-02-17 11:09:47.341184 [DEBUG] sofia.c:7406 Channel sofia/internal/101@dev.mtuan.com entering state [ready][200]
2022-02-17 11:09:47.361225 [DEBUG] switch_rtp.c:7793 Correct audio ip/port confirmed.
2022-02-17 11:09:47.401199 [DEBUG] switch_rtp.c:7793 Correct audio ip/port confirmed.
2022-02-17 11:09:49.341173 [DEBUG] switch_rtp.c:7191 Correct audio RTCP ip/port confirmed.
2022-02-17 11:09:50.561171 [DEBUG] switch_rtp.c:7191 Correct audio RTCP ip/port confirmed.
freeswitch@cluster-fs>
freeswitch@cluster-fs>
freeswitch@cluster-fs>
freeswitch@cluster-fs>
freeswitch@cluster-fs>
2022-02-17 11:09:53.801170 [NOTICE] sofia.c:1090 Hangup sofia/internal/101@dev.mtuan.com [CS_EXECUTE] [NORMAL_CLEARING]
2022-02-17 11:09:53.801170 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/internal/101@dev.mtuan.com]
2022-02-17 11:09:53.801170 [DEBUG] switch_ivr_bridge.c:820 sofia/internal/101@dev.mtuan.com ending bridge by request from write function
2022-02-17 11:09:53.801170 [DEBUG] switch_ivr_bridge.c:912 BRIDGE THREAD DONE [sofia/external/0965138057]
2022-02-17 11:09:53.801170 [NOTICE] switch_ivr_bridge.c:1029 Hangup sofia/external/0965138057 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:654 (sofia/external/0965138057) State EXCHANGE_MEDIA going to sleep
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:585 (sofia/external/0965138057) Running State Change CS_HANGUP (Cur 2 Tot 2)
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:848 (sofia/external/0965138057) Callstate Change ACTIVE -> HANGUP
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:850 (sofia/external/0965138057) State HANGUP
2022-02-17 11:09:53.801170 [DEBUG] mod_sofia.c:447 sofia/external/0965138057 Overriding SIP cause 480 with 200 from the other leg
2022-02-17 11:09:53.801170 [DEBUG] mod_sofia.c:453 Channel sofia/external/0965138057 hanging up, cause: NORMAL_CLEARING
2022-02-17 11:09:53.801170 [DEBUG] mod_sofia.c:507 Sending BYE to sofia/external/0965138057
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:60 sofia/external/0965138057 Standard HANGUP, cause: NORMAL_CLEARING
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:850 (sofia/external/0965138057) State HANGUP going to sleep
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:620 (sofia/external/0965138057) State Change CS_HANGUP -> CS_REPORTING
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:585 (sofia/external/0965138057) Running State Change CS_REPORTING (Cur 2 Tot 2)
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:936 (sofia/external/0965138057) State REPORTING
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:174 sofia/external/0965138057 Standard REPORTING, cause: NORMAL_CLEARING
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:936 (sofia/external/0965138057) State REPORTING going to sleep
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:611 (sofia/external/0965138057) State Change CS_REPORTING -> CS_DESTROY
2022-02-17 11:09:53.801170 [DEBUG] switch_core_session.c:1736 Session 2 (sofia/external/0965138057) Locked, Waiting on external entities
2022-02-17 11:09:53.801170 [DEBUG] switch_ivr_bridge.c:1895 sofia/internal/101@dev.mtuan.com skip receive message [UNBRIDGE] (channel is hungup already)
2022-02-17 11:09:53.801170 [NOTICE] switch_core_session.c:1754 Session 2 (sofia/external/0965138057) Ended
2022-02-17 11:09:53.801170 [NOTICE] switch_core_session.c:1758 Close Channel sofia/external/0965138057 [CS_DESTROY]
2022-02-17 11:09:53.801170 [DEBUG] switch_core_session.c:2914 sofia/internal/101@dev.mtuan.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/101@dev.mtuan.com) State EXECUTE going to sleep
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/101@dev.mtuan.com) Running State Change CS_HANGUP (Cur 1 Tot 2)
2022-02-17 11:09:53.801170 [DEBUG] switch_ivr_async.c:1520 Stop recording file /usr/local/freeswitch/recordings/dev.mtuan.com/archive/2022/Feb/17/8b761da4-a00a-4ab6-9a5a-6146d05bb62e.mp3
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:739 (sofia/external/0965138057) Running State Change CS_DESTROY (Cur 1 Tot 2)
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:749 (sofia/external/0965138057) State DESTROY
2022-02-17 11:09:53.801170 [DEBUG] mod_sofia.c:364 sofia/external/0965138057 SOFIA DESTROY
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:181 sofia/external/0965138057 Standard DESTROY
2022-02-17 11:09:53.801170 [DEBUG] switch_core_state_machine.c:749 (sofia/external/0965138057) State DESTROY going to sleep
2022-02-17 11:09:53.821168 [DEBUG] switch_ivr_async.c:1597 Channel is hung up
2022-02-17 11:09:53.821168 [DEBUG] switch_core_media_bug.c:1312 Removing BUG from sofia/internal/101@dev.mtuan.com
2022-02-17 11:09:53.821168 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/101@dev.mtuan.com) Callstate Change ACTIVE -> HANGUP
2022-02-17 11:09:53.821168 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/101@dev.mtuan.com) State HANGUP
2022-02-17 11:09:53.821168 [DEBUG] mod_sofia.c:453 Channel sofia/internal/101@dev.mtuan.com hanging up, cause: NORMAL_CLEARING
2022-02-17 11:09:53.821168 [DEBUG] switch_core_state_machine.c:60 sofia/internal/101@dev.mtuan.com Standard HANGUP, cause: NORMAL_CLEARING
2022-02-17 11:09:53.821168 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/101@dev.mtuan.com) State HANGUP going to sleep
2022-02-17 11:09:53.821168 [DEBUG] switch_core_state_machine.c:620 (sofia/internal/101@dev.mtuan.com) State Change CS_HANGUP -> CS_REPORTING
2022-02-17 11:09:53.821168 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/101@dev.mtuan.com) Running State Change CS_REPORTING (Cur 1 Tot 2)
2022-02-17 11:09:53.821168 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/101@dev.mtuan.com) State REPORTING
2022-02-17 11:09:54.021192 [DEBUG] switch_core_state_machine.c:174 sofia/internal/101@dev.mtuan.com Standard REPORTING, cause: NORMAL_CLEARING
2022-02-17 11:09:54.021192 [DEBUG] switch_core_state_machine.c:936 (sofia/internal/101@dev.mtuan.com) State REPORTING going to sleep
2022-02-17 11:09:54.021192 [DEBUG] switch_core_state_machine.c:611 (sofia/internal/101@dev.mtuan.com) State Change CS_REPORTING -> CS_DESTROY
2022-02-17 11:09:54.021192 [DEBUG] switch_core_session.c:1736 Session 1 (sofia/internal/101@dev.mtuan.com) Locked, Waiting on external entities
2022-02-17 11:09:54.021192 [NOTICE] switch_core_session.c:1754 Session 1 (sofia/internal/101@dev.mtuan.com) Ended
2022-02-17 11:09:54.021192 [NOTICE] switch_core_session.c:1758 Close Channel sofia/internal/101@dev.mtuan.com [CS_DESTROY]
2022-02-17 11:09:54.021192 [DEBUG] switch_core_state_machine.c:739 (sofia/internal/101@dev.mtuan.com) Running State Change CS_DESTROY (Cur 0 Tot 2)
2022-02-17 11:09:54.021192 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/101@dev.mtuan.com) State DESTROY
2022-02-17 11:09:54.021192 [DEBUG] mod_sofia.c:364 sofia/internal/101@dev.mtuan.com SOFIA DESTROY
2022-02-17 11:09:54.021192 [DEBUG] switch_core_state_machine.c:181 sofia/internal/101@dev.mtuan.com Standard DESTROY
2022-02-17 11:09:54.021192 [DEBUG] switch_core_state_machine.c:749 (sofia/internal/101@dev.mtuan.com) State DESTROY going to sleep
It's seem like there something to be done with freeswitch mod_lua and xml_handler, hope that someone can help me with this.
 

Attachments

  • 1645070017778.png
    1645070017778.png
    60.3 KB · Views: 10
Last edited:
Status
Not open for further replies.