Sure, please find below a redacted one.
Setup is:
IP Phone (local 192.168.1.20) <-> NAT Router A <-> Internet <-> NAT Router B <-> Fusion PBX (local IP 192.168.0.10)
Many Thanks for any help!
=================================================================================================
Name internal
Domain Name N/A
Auto-NAT false
DBName sofia_reg_internal
Pres Hosts
Dialplan XML
Context public
Challenge Realm auto_to
RTP-IP 192.168.0.10
SIP-IP 192.168.0.10
URL sip:mod_sofia@192.168.0.10:5060
BIND-URL sip:mod_sofia@192.168.0.10:5060;transport=udp,tcp
HOLD-MUSIC local_stream://default
OUTBOUND-PROXY N/A
CODECS IN G7221@32000h,G7221@16000h,G722,PCMU,PCMA,GSM
CODECS OUT G7221@32000h,G7221@16000h,G722,PCMU,PCMA,GSM
TEL-EVENT 101
DTMF-MODE rfc2833
CNG 13
SESSION-TO 0
MAX-DIALOG 0
NOMEDIA false
LATE-NEG false
PROXY-MEDIA false
ZRTP-PASSTHRU false
AGGRESSIVENAT true
CALLS-IN 210
FAILED-CALLS-IN 28
CALLS-OUT 230
FAILED-CALLS-OUT 140
REGISTRATIONS 5
2018-04-24 03:54:36.149366 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [120@192.168.0.10] from ip <<remote.ip.domain>>
2018-04-24 03:55:06.649354 [DEBUG] sofia.c:9873 sofia/internal/120@192.168.0.10:5060 receiving invite from <<remote.ip.domain>>:12406 version: 1.6.20 -37-987c9b9 64bit
2018-04-24 03:55:06.649354 [DEBUG] sofia.c:10044 IP <<remote.ip.domain>> Rejected by acl "domains". Falling back to Digest auth.
2018-04-24 03:55:06.649354 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [<<Tel called>>@192.168.0.10] from ip <<remote.ip.domain>>
2018-04-24 03:55:06.649354 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/120@192.168.0.10:5060) State NEW
2018-04-24 03:55:06.649354 [DEBUG] sofia.c:2334 detaching session a118a857-9cb7-4260-bd54-3d8d7d3656a6
2018-04-24 03:55:06.709253 [DEBUG] sofia.c:2442 Re-attaching to session a118a857-9cb7-4260-bd54-3d8d7d3656a6
2018-04-24 03:55:06.729304 [DEBUG] sofia.c:9873 sofia/internal/120@192.168.0.10:5060 receiving invite from <<remote.ip.domain>>:12406 version: 1.6.20 -37-987c9b9 64bit
2018-04-24 03:55:06.729304 [DEBUG] sofia.c:10044 IP <<remote.ip.domain>> Rejected by acl "domains". Falling back to Digest auth.
2018-04-24 03:55:06.729304 [DEBUG] sofia.c:11168 Setting NAT mode based on via received
2018-04-24 03:55:06.729304 [DEBUG] sofia.c:7084 Channel sofia/internal/120@192.168.0.10:5060 entering state [received][100]
2018-04-24 03:55:06.729304 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=- 20055 20055 IN IP4 192.168.1.20
s=SDP data
c=IN IP4 192.168.1.20
t=0 0
m=audio 21878 RTP/AVP 107 9 0 8 18 101
a=rtpmap:107 opus/48000/2
a=fmtp:107 sprop-maxcapturerate=16000; maxaveragebitrate=20000; maxplaybackrate=48000
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
2018-04-24 03:55:06.729304 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [opus:107:48000:20:0:2]/[G722:9:8000:20:64000:1]
2018-04-24 03:55:06.729304 [DEBUG] sofia.c:7507 (sofia/internal/120@192.168.0.10:5060) State Change CS_NEW -> CS_INIT
2018-04-24 03:55:06.729304 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/120@192.168.0.10:5060) Running State Change CS_INIT (Cur 1 Tot 371)
2018-04-24 03:55:06.729304 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/120@192.168.0.10:5060) State INIT
2018-04-24 03:55:06.729304 [DEBUG] mod_sofia.c:90 sofia/internal/120@192.168.0.10:5060 SOFIA INIT
2018-04-24 03:55:06.729304 [DEBUG] switch_core_state_machine.c:40 sofia/internal/120@192.168.0.10:5060 Standard INIT
2018-04-24 03:55:06.729304 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/120@192.168.0.10:5060) State Change CS_INIT -> CS_ROUTING
2018-04-24 03:55:06.729304 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/120@192.168.0.10:5060) State INIT going to sleep
2018-04-24 03:55:06.729304 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/120@192.168.0.10:5060) Running State Change CS_ROUTING (Cur 1 Tot 371)
2018-04-24 03:55:06.729304 [DEBUG] switch_channel.c:2249 (sofia/internal/120@192.168.0.10:5060) Callstate Change DOWN -> RINGING
2018-04-24 03:55:06.729304 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/120@192.168.0.10:5060) State ROUTING
2018-04-24 03:55:06.729304 [DEBUG] mod_sofia.c:143 sofia/internal/120@192.168.0.10:5060 SOFIA ROUTING
2018-04-24 03:55:06.729304 [DEBUG] switch_core_state_machine.c:236 sofia/internal/120@192.168.0.10:5060 Standard ROUTING
2018-04-24 03:55:06.729304 [INFO] mod_dialplan_xml.c:637 Processing Office <120>-><<Tel called>> in context 192.168.0.10
Dialplan: sofia/internal/120@192.168.0.10:5060 parsing [192.168.0.10->user_exists] continue=true
Dialplan: sofia/internal/120@192.168.0.10:5060 Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
2018-04-24 03:55:06.749245 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f3388052760 Connected.
2018-04-24 03:55:06.749245 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f3388052760 released.
EXECUTE sofia/internal/120@192.168.0.10:5060 set(user_exists=false)
2018-04-24 03:55:06.749245 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [user_exists]=[false]
Dialplan: sofia/internal/120@192.168.0.10:5060 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/120@192.168.0.10:5060 parsing [192.168.0.10->call-direction] continue=true
Dialplan: sofia/internal/120@192.168.0.10:5060 Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/internal/120@192.168.0.10:5060 ANTI-Action set(call_direction=local)
Dialplan: sofia/internal/120@192.168.0.10:5060 parsing [192.168.0.10->variables] continue=true
Dialplan: sofia/internal/120@192.168.0.10:5060 Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/internal/120@192.168.0.10:5060 Action export(origination_callee_id_name=${destination_number})
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/120@192.168.0.10:5060 parsing [192.168.0.10->user_record] continue=true
Dialplan: sofia/internal/120@192.168.0.10:5060 Regex (PASS) [user_record] () =~ // break=on-false
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
2018-04-24 03:55:06.749245 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f3388052760 Connected.
2018-04-24 03:55:06.749245 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f3388052760 released.
2018-04-24 03:55:06.749245 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f3388052760 Connected.
2018-04-24 03:55:06.749245 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f3388052760 released.
EXECUTE sofia/internal/120@192.168.0.10:5060 set(user_record=)
2018-04-24 03:55:06.749245 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [user_record]=[UNDEF]
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
EXECUTE sofia/internal/120@192.168.0.10:5060 set(from_user_exists=true)
2018-04-24 03:55:06.749245 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [from_user_exists]=[true]
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(sip_h_X-accountcode=${accountcode})
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(call_direction=outbound)
Dialplan: sofia/internal/120@192.168.0.10:5060 Action unset(call_timeout)
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(effective_caller_id_name=${outbound_caller_id_name})
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(effective_caller_id_number=${outbound_caller_id_number})
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(inherit_codec=true)
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(ignore_display_updates=true)
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(callee_id_number=<<Tel called>>)
Dialplan: sofia/internal/120@192.168.0.10:5060 Action set(continue_on_fail=true)
Dialplan: sofia/internal/120@192.168.0.10:5060 Action bridge(sofia/gateway/a2a13654-dd66-438d-b7bd-a2a4ba6873de/<<Tel called>>)
Dialplan: sofia/internal/120@192.168.0.10:5060 Action bridge(sofia/gateway/edcc66a3-3889-49e4-8ae6-13a23e391b9a/<<Tel called>>)
Dialplan: sofia/internal/120@192.168.0.10:5060 Action bridge(sofia/gateway/34ca4d63-125b-40e5-b1df-d15e238a3b50/<<Tel called>>)
Dialplan: sofia/internal/120@192.168.0.10:5060 Action bridge(sofia/gateway/75e1d59f-974f-4378-8092-1129c0765937/<<Tel called>>)
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/120@192.168.0.10:5060) State Change CS_ROUTING -> CS_EXECUTE
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/120@192.168.0.10:5060) State ROUTING going to sleep
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/120@192.168.0.10:5060) Running State Change CS_EXECUTE (Cur 1 Tot 371)
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/120@192.168.0.10:5060) State EXECUTE
2018-04-24 03:55:06.769243 [DEBUG] mod_sofia.c:198 sofia/internal/120@192.168.0.10:5060 SOFIA EXECUTE
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:328 sofia/internal/120@192.168.0.10:5060 Standard EXECUTE
EXECUTE sofia/internal/120@192.168.0.10:5060 set(call_direction=local)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [call_direction]=[local]
EXECUTE sofia/internal/120@192.168.0.10:5060 export(origination_callee_id_name=<<Tel called>>)
2018-04-24 03:55:06.769243 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[<<Tel called>>]
EXECUTE sofia/internal/120@192.168.0.10:5060 set(RFC2822_DATE=Tue, 24 Apr 2018 03:55:06 -0400)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [RFC2822_DATE]=[Tue, 24 Apr 2018 03:55:06 -0400]
EXECUTE sofia/internal/120@192.168.0.10:5060 hash(insert/192.168.0.10-last_dial/120/<<Tel called>>)
EXECUTE sofia/internal/120@192.168.0.10:5060 set(sip_h_X-accountcode=192.168.0.10)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [sip_h_X-accountcode]=[192.168.0.10]
EXECUTE sofia/internal/120@192.168.0.10:5060 set(call_direction=outbound)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [call_direction]=[outbound]
EXECUTE sofia/internal/120@192.168.0.10:5060 unset(call_timeout)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1693 UNSET [call_timeout]
EXECUTE sofia/internal/120@192.168.0.10:5060 set(hangup_after_bridge=true)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [hangup_after_bridge]=[true]
EXECUTE sofia/internal/120@192.168.0.10:5060 set(effective_caller_id_name=)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [effective_caller_id_name]=[UNDEF]
EXECUTE sofia/internal/120@192.168.0.10:5060 set(effective_caller_id_number=)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [effective_caller_id_number]=[UNDEF]
EXECUTE sofia/internal/120@192.168.0.10:5060 set(inherit_codec=true)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [inherit_codec]=[true]
EXECUTE sofia/internal/120@192.168.0.10:5060 set(ignore_display_updates=true)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [ignore_display_updates]=[true]
EXECUTE sofia/internal/120@192.168.0.10:5060 set(callee_id_number=<<Tel called>>)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [callee_id_number]=[<<Tel called>>]
EXECUTE sofia/internal/120@192.168.0.10:5060 set(continue_on_fail=true)
2018-04-24 03:55:06.769243 [DEBUG] mod_dptools.c:1548 SET sofia/internal/120@192.168.0.10:5060 [continue_on_fail]=[true]
EXECUTE sofia/internal/120@192.168.0.10:5060 bridge(sofia/gateway/a2a13654-dd66-438d-b7bd-a2a4ba6873de/<<Tel called>>)
2018-04-24 03:55:06.769243 [DEBUG] switch_channel.c:1250 sofia/internal/120@192.168.0.10:5060 EXPORTING[export_vars] [domain_name]=[192.168.0.10] to event
2018-04-24 03:55:06.769243 [DEBUG] switch_channel.c:1250 sofia/internal/120@192.168.0.10:5060 EXPORTING[export_vars] [origination_callee_id_name]=[<<Tel called>>] to event
2018-04-24 03:55:06.769243 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-04-24 03:55:06.769243 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/<<Tel called>> [a701f96b-fce0-45b2-a6ea-28a8083b4ff8]
2018-04-24 03:55:06.769243 [DEBUG] mod_sofia.c:4819 (sofia/internal/<<Tel called>>) State Change CS_NEW -> CS_INIT
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/<<Tel called>>) Running State Change CS_INIT (Cur 2 Tot 372)
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/<<Tel called>>) State INIT
2018-04-24 03:55:06.769243 [DEBUG] mod_sofia.c:90 sofia/internal/<<Tel called>> SOFIA INIT
2018-04-24 03:55:06.769243 [DEBUG] sofia_glue.c:1295 sofia/internal/<<Tel called>> sending invite version: 1.6.20 -37-987c9b9 64bit
Local SDP:
v=0
o=FreeSWITCH 1524531412 1524531413 IN IP4 192.168.0.10
s=FreeSWITCH
c=IN IP4 192.168.0.10
t=0 0
m=audio 25094 RTP/AVP 9 0 8 3 101 13
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:40 sofia/internal/<<Tel called>> Standard INIT
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/<<Tel called>>) State Change CS_INIT -> CS_ROUTING
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/<<Tel called>>) State INIT going to sleep
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/<<Tel called>>) Running State Change CS_ROUTING (Cur 2 Tot 372)
2018-04-24 03:55:06.769243 [DEBUG] sofia.c:7084 Channel sofia/internal/<<Tel called>> entering state [calling][0]
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/<<Tel called>>) State ROUTING
2018-04-24 03:55:06.769243 [DEBUG] mod_sofia.c:143 sofia/internal/<<Tel called>> SOFIA ROUTING
2018-04-24 03:55:06.769243 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/<<Tel called>>) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/<<Tel called>>) State ROUTING going to sleep
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/<<Tel called>>) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 372)
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/<<Tel called>>) State CONSUME_MEDIA
2018-04-24 03:55:06.769243 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/<<Tel called>>) State CONSUME_MEDIA going to sleep
2018-04-24 03:55:09.669430 [DEBUG] sofia.c:7084 Channel sofia/internal/<<Tel called>> entering state [proceeding][180]
2018-04-24 03:55:09.669430 [NOTICE] sofia.c:7192 Ring-Ready sofia/internal/<<Tel called>>!
2018-04-24 03:55:09.669430 [DEBUG] switch_channel.c:3346 (sofia/internal/<<Tel called>>) Callstate Change DOWN -> RINGING
2018-04-24 03:55:09.689251 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/internal/120@192.168.0.10:5060!
2018-04-24 03:55:09.689251 [DEBUG] sofia.c:7084 Channel sofia/internal/120@192.168.0.10:5060 entering state [early][180]
2018-04-24 03:55:09.689251 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/internal/120@192.168.0.10:5060!
2018-04-24 03:55:23.409341 [DEBUG] sofia.c:7084 Channel sofia/internal/<<Tel called>> entering state [completing][200]
2018-04-24 03:55:23.409341 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=40196 8001 8000 IN IP4 192.168.0.11
s=SIP Call
c=IN IP4 192.168.0.11
t=0 0
m=audio 5008 RTP/AVP 0 8 4 18 3 2 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-11
a=ptime:20
2018-04-24 03:55:23.409341 [DEBUG] sofia.c:7084 Channel sofia/internal/<<Tel called>> entering state [ready][200]
2018-04-24 03:55:23.409341 [DEBUG] switch_core_media.c:7210 sofia/internal/<<Tel called>> Set rtp dtmf delay to 40
2018-04-24 03:55:23.409341 [NOTICE] sofia.c:8218 Channel [sofia/internal/<<Tel called>>] has been answered
2018-04-24 03:55:23.409341 [DEBUG] switch_channel.c:3773 (sofia/internal/<<Tel called>>) Callstate Change RINGING -> ACTIVE
2018-04-24 03:55:23.429254 [DEBUG] switch_ivr_originate.c:410 Setting codec string on sofia/internal/120@192.168.0.10:5060 to PCMU@8000h@20i
2018-04-24 03:55:23.429254 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/120@192.168.0.10:5060] 192.168.0.10 port 23012 -> 192.168.1.20 port 21878 codec: 9 ms: 20
2018-04-24 03:55:23.429254 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/120@192.168.0.10:5060:
v=0
o=FreeSWITCH 1524533511 1524533512 IN IP4 192.168.0.10
s=FreeSWITCH
c=IN IP4 192.168.0.10
t=0 0
m=audio 23012 RTP/AVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
2018-04-24 03:55:23.429254 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/internal/120@192.168.0.10:5060] has been answered
2018-04-24 03:55:23.429254 [DEBUG] switch_channel.c:3773 (sofia/internal/120@192.168.0.10:5060) Callstate Change RINGING -> ACTIVE
2018-04-24 03:55:23.429254 [DEBUG] sofia.c:7084 Channel sofia/internal/120@192.168.0.10:5060 entering state [completed][200]
2018-04-24 03:55:23.429254 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/<<Tel called>>]
2018-04-24 03:55:23.429254 [DEBUG] switch_ivr_bridge.c:1614 (sofia/internal/<<Tel called>>) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2018-04-24 03:55:23.429254 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/<<Tel called>>) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 372)
2018-04-24 03:55:23.429254 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/<<Tel called>>) State EXCHANGE_MEDIA
2018-04-24 03:55:23.429254 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
2018-04-24 03:55:23.469243 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
2018-04-24 03:55:23.469243 [NOTICE] switch_core_io.c:1202 Activating write resampler
2018-04-24 03:55:28.769407 [DEBUG] switch_ivr_bridge.c:706 sofia/internal/120@192.168.0.10:5060 ending bridge by request from write function
2018-04-24 03:55:28.769407 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/<<Tel called>>) State REPORTING going to sleep
2018-04-24 03:55:28.769407 [DEBUG] switch_core_state_machine.c:60 sofia/internal/120@192.168.0.10:5060 Standard HANGUP, cause: NORMAL_CLEARING