NAT misconfigured symptoms

Status
Not open for further replies.

Win

Member
Feb 12, 2024
49
2
8
Hi,

my FusionPBX has NAT misconfigured symptoms: (Outbound call drops after 32 seconds and no audio)

Re to: https://docs.fusionpbx.com/en/latest/additional_information/nat.html

what I have done:

- internal sip profile --> I set external_rtp_ip and external_sip_ip $${local_ip_v4} and enabled.
- external sip profile --> I set ext-rtp-ip and sip_rtp_ip to my ip public
- iptables --> forward udp 5060-5091 and also forward udp 10000-40000

and set /etc/freeswitch/autoload_configs/switch.conf.xml

<!-- RTP port range -->
<param name="rtp-start-port" value="10000"/>
<param name="rtp-end-port" value="40000"/>

and restarted the server!, but still facing the same..

anybody can give me a suggestion or advice?

thanks
 

Attachments

  • nat issue.png
    nat issue.png
    209 KB · Views: 11
Last edited:

voipBull

Member
Dec 3, 2023
96
21
8
Its taking your FusionPBX 32secs to respond with a ACK to the previous 200 OK..?!?!? and then it sends a BYE right after. You may need to look into the Freeswitch logs about that.
Why are you advertising other ends IP 43.245.185.3 in your INVITE's SDP? Your PBX Public IP needs to go there.
 

Attachments

  • 1708012169953.png
    1708012169953.png
    244.1 KB · Views: 4

Win

Member
Feb 12, 2024
49
2
8
Hi @voipBull

you wrote "..Why are you advertising other ends IP 43.245.185.3 in your INVITE's SDP? Your PBX Public IP needs to go there."

is this related to the dialplan?, sorry, I didn't get you
 

voipBull

Member
Dec 3, 2023
96
21
8
No, not the dialplan, but your SIP profiles. In your external profile set "ext-rtp-ip" and "sip_rtp_ip" to "autonat:your_pbx_public_ip" (without the quotes ofcourse). If this is cloud install, then you'll probably need to do the same for your internal profile as well so that phones/endpoint don't experience the same NAT issue. Then Status > SIP status > Flush cache & Reload
 

Win

Member
Feb 12, 2024
49
2
8
Hi @voipBull,

I have tried to set my external profile as suggested, and yes, now I ABLE to hear the audio when OUTBOUND CALL! :) but the outbound call still drops at 32 secs.

I also have tried to set my internal profile as suggested, but I'm UNABLE to hear the audio when INBOUND CALL :(, and the inbound call also drops at 32 secs.

any idea?
 

Attachments

  • nat issue outbound.png
    nat issue outbound.png
    208.8 KB · Views: 4
  • nat issue inbound.png
    nat issue inbound.png
    203.1 KB · Views: 4

voipBull

Member
Dec 3, 2023
96
21
8
Thats most likely because of no ACK or delayed ACK to 200 OK. Look into your Freeswitch logs what happens after it receives the 200 OK.
 

Win

Member
Feb 12, 2024
49
2
8
from the log, I see

mod_sofia.c:469 Channel sofia/internal/101@pbx.example.com hanging up, cause: MANDATORY_IE_MISSING

this might be the root cause of the issue! (drops after 32secs and no voice), but I don't have any idea for this, I'm stuck.

can you please help me?

freeswitch@pbx> sofia status profile 622112345678-external
===================
Name 622112345678-external
Domain Name N/A
Auto-NAT false
DBName sofia_reg_622112345678-external
Pres Hosts
Dialplan XML
Context public
Challenge Realm auto_to
RTP-IP 172.31.203.210
Ext-RTP-IP 43.1.2.3
SIP-IP 172.31.203.210
Ext-SIP-IP 43.1.2.3
URL sip:mod_sofia@43.1.2.3:5080
BIND-URL sip:mod_sofia@43.1.2.3:5080;maddr=172.31.203.210;transport=udp,tcp
HOLD-MUSIC local_stream://default
OUTBOUND-PROXY N/A
CODECS IN G7221@32000h,G7221@16000h,G722,PCMU,PCMA
CODECS OUT PCMU,PCMA
TEL-EVENT 101
DTMF-MODE rfc2833
CNG 0
SESSION-TO 0
MAX-DIALOG 0
MAX-RECV-RPS 1000
NOMEDIA false
LATE-NEG true
PROXY-MEDIA false
AGGRESSIVENAT true
CALLS-IN 4
FAILED-CALLS-IN 0
CALLS-OUT 4
FAILED-CALLS-OUT 0
REGISTRATIONS 0



=== log ===


Displaying the last 524,288 of 5,451,408 bytes.
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:745 (sofia/622112345678-external/0817123456) State DESTROY going to sleep
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:175 sofia/622112345678-external/0817123456 Standard DESTROY
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] mod_sofia.c:380 sofia/622112345678-external/0817123456 SOFIA DESTROY
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:745 (sofia/622112345678-external/0817123456) State DESTROY
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:735 (sofia/622112345678-external/0817123456) Running State Change CS_DESTROY (Cur 0 Tot 57)
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [NOTICE] switch_core_session.c:1766 Close Channel sofia/622112345678-external/0817123456 [CS_DESTROY]
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [NOTICE] switch_core_session.c:1762 Session 57 (sofia/622112345678-external/0817123456) Ended
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_session.c:1744 Session 57 (sofia/622112345678-external/0817123456) Locked, Waiting on external entities
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:607 (sofia/622112345678-external/0817123456) State Change CS_REPORTING -> CS_DESTROY
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:932 (sofia/622112345678-external/0817123456) State REPORTING going to sleep
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:168 sofia/622112345678-external/0817123456 Standard REPORTING, cause: MANDATORY_IE_MISSING
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:932 (sofia/622112345678-external/0817123456) State REPORTING
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:581 (sofia/622112345678-external/0817123456) Running State Change CS_REPORTING (Cur 1 Tot 57)
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:616 (sofia/622112345678-external/0817123456) State Change CS_HANGUP -> CS_REPORTING
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:846 (sofia/622112345678-external/0817123456) State HANGUP going to sleep
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:59 sofia/622112345678-external/0817123456 Standard HANGUP, cause: MANDATORY_IE_MISSING
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/101@pbx.example.com) State DESTROY going to sleep
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:175 sofia/internal/101@pbx.example.com Standard DESTROY
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] mod_sofia.c:380 sofia/internal/101@pbx.example.com SOFIA DESTROY
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/101@pbx.example.com) State DESTROY
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] mod_sofia.c:523 Sending BYE to sofia/622112345678-external/0817123456
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/101@pbx.example.com) Running State Change CS_DESTROY (Cur 1 Tot 57)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [NOTICE] switch_core_session.c:1766 Close Channel sofia/internal/101@pbx.example.com [CS_DESTROY]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [NOTICE] switch_core_session.c:1762 Session 56 (sofia/internal/101@pbx.example.com) Ended
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_session.c:1744 Session 56 (sofia/internal/101@pbx.example.com) Locked, Waiting on external entities
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/101@pbx.example.com) State Change CS_REPORTING -> CS_DESTROY
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/101@pbx.example.com) State REPORTING going to sleep
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:168 sofia/internal/101@pbx.example.com Standard REPORTING, cause: MANDATORY_IE_MISSING
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/101@pbx.example.com) State REPORTING
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] mod_sofia.c:469 Channel sofia/622112345678-external/0817123456 hanging up, cause: MANDATORY_IE_MISSING
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:846 (sofia/622112345678-external/0817123456) State HANGUP
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:844 (sofia/622112345678-external/0817123456) Callstate Change ACTIVE -> HANGUP
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.com) Running State Change CS_REPORTING (Cur 2 Tot 57)
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:581 (sofia/622112345678-external/0817123456) Running State Change CS_HANGUP (Cur 2 Tot 57)
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_ivr_bridge.c:1334 sofia/622112345678-external/0817123456 skip receive message [UNBRIDGE] (channel is hungup already)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/101@pbx.example.com) State Change CS_HANGUP -> CS_REPORTING
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/101@pbx.example.com) State HANGUP going to sleep
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:59 sofia/internal/101@pbx.example.com Standard HANGUP, cause: MANDATORY_IE_MISSING
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:45.035686 48.83% [NOTICE] switch_ivr_bridge.c:1473 Hangup sofia/622112345678-external/0817123456 [CS_HIBERNATE] [MANDATORY_IE_MISSING]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] mod_sofia.c:469 Channel sofia/internal/101@pbx.example.com hanging up, cause: MANDATORY_IE_MISSING
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/101@pbx.example.com) State HANGUP
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/101@pbx.example.com) Callstate Change ACTIVE -> HANGUP
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.com) Running State Change CS_HANGUP (Cur 2 Tot 57)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] switch_ivr_bridge.c:1334 sofia/internal/101@pbx.example.com skip receive message [UNBRIDGE] (channel is hungup already)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [NOTICE] sofia.c:8735 Hangup sofia/internal/101@pbx.example.com [CS_HIBERNATE] [MANDATORY_IE_MISSING]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:45.035686 48.83% [DEBUG] sofia.c:7493 Channel sofia/internal/101@pbx.example.com entering state [terminating][0]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:13.035685 48.93% [DEBUG] sofia.c:7493 Channel sofia/internal/101@pbx.example.com entering state [completed][200]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:13.035685 48.93% [DEBUG] switch_channel.c:3912 (sofia/internal/101@pbx.example.com) Callstate Change EARLY -> ACTIVE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:13.035685 48.93% [NOTICE] switch_ivr.c:820 Channel [sofia/internal/101@pbx.example.com] has been answered
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:13.035685 48.93% [DEBUG] switch_channel.c:3912 (sofia/622112345678-external/0817123456) Callstate Change EARLY -> ACTIVE
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:13.035685 48.93% [NOTICE] sofia.c:8622 Channel [sofia/622112345678-external/0817123456] has been answered
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:13.035685 48.93% [DEBUG] sofia.c:7493 Channel sofia/622112345678-external/0817123456 entering state [ready][200]
0008038c-7722-43e9-b01a-92c9458b259c
0008038c-7722-43e9-b01a-92c9458b259c a=fmtp:101 0-15
0008038c-7722-43e9-b01a-92c9458b259c a=rtpmap:101 telephone-event/8000
0008038c-7722-43e9-b01a-92c9458b259c a=rtpmap:8 PCMA/8000
0008038c-7722-43e9-b01a-92c9458b259c m=audio 10608 RTP/AVP 8 101
0008038c-7722-43e9-b01a-92c9458b259c t=0 0
0008038c-7722-43e9-b01a-92c9458b259c c=IN IP4 -
0008038c-7722-43e9-b01a-92c9458b259c s=-
0008038c-7722-43e9-b01a-92c9458b259c o=GANG 744040838 744040839 IN IP4 43.1.2.31.2.3245.185.3
0008038c-7722-43e9-b01a-92c9458b259c v=0
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:13.035685 48.93% [DEBUG] sofia.c:7500 Duplicate SDP
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:13.035685 48.93% [DEBUG] sofia.c:7493 Channel sofia/622112345678-external/0817123456 entering state [completing][200]
0008038c-7722-43e9-b01a-92c9458b259c
0008038c-7722-43e9-b01a-92c9458b259c a=fmtp:101 0-15
0008038c-7722-43e9-b01a-92c9458b259c a=rtpmap:101 telephone-event/8000
0008038c-7722-43e9-b01a-92c9458b259c a=rtpmap:8 PCMA/8000
0008038c-7722-43e9-b01a-92c9458b259c m=audio 10608 RTP/AVP 8 101
0008038c-7722-43e9-b01a-92c9458b259c t=0 0
0008038c-7722-43e9-b01a-92c9458b259c c=IN IP4 43.1.2.31.2.3245.185.3
0008038c-7722-43e9-b01a-92c9458b259c s=-
0008038c-7722-43e9-b01a-92c9458b259c o=GANG 744040838 744040839 IN IP4 43.1.2.31.2.3245.185.3
0008038c-7722-43e9-b01a-92c9458b259c v=0
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:06.815682 49.07% [DEBUG] sofia.c:7500 Duplicate SDP
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:06.815682 49.07% [DEBUG] sofia.c:7493 Channel sofia/622112345678-external/0817123456 entering state [proceeding][180]
0008038c-7722-43e9-b01a-92c9458b259c
0008038c-7722-43e9-b01a-92c9458b259c a=fmtp:101 0-15
0008038c-7722-43e9-b01a-92c9458b259c a=rtpmap:101 telephone-event/8000
0008038c-7722-43e9-b01a-92c9458b259c a=rtpmap:8 PCMA/8000
0008038c-7722-43e9-b01a-92c9458b259c m=audio 10608 RTP/AVP 8 101
0008038c-7722-43e9-b01a-92c9458b259c t=0 0
0008038c-7722-43e9-b01a-92c9458b259c c=IN IP4 43.1.2.31.2.3245.185.3
0008038c-7722-43e9-b01a-92c9458b259c s=-
0008038c-7722-43e9-b01a-92c9458b259c o=GANG 744040838 744040839 IN IP4 43.1.2.31.2.3245.185.3
0008038c-7722-43e9-b01a-92c9458b259c v=0
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:06.775683 49.07% [DEBUG] sofia.c:7500 Duplicate SDP
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:06.775683 49.07% [DEBUG] sofia.c:7493 Channel sofia/622112345678-external/0817123456 entering state [proceeding][180]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.435683 49.03% [DEBUG] switch_core_state_machine.c:662 (sofia/internal/101@pbx.example.com) State HIBERNATE going to sleep
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.435683 49.03% [DEBUG] switch_core_state_machine.c:417 sofia/internal/101@pbx.example.com Standard HIBERNATE
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_core_state_machine.c:662 (sofia/622112345678-external/0817123456) State HIBERNATE going to sleep
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_core_state_machine.c:417 sofia/622112345678-external/0817123456 Standard HIBERNATE
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:02.415684 49.03% [DEBUG] mod_sofia.c:195 sofia/622112345678-external/0817123456 SOFIA HIBERNATE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.415684 49.03% [DEBUG] mod_sofia.c:195 sofia/internal/101@pbx.example.com SOFIA HIBERNATE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_core_state_machine.c:662 (sofia/internal/101@pbx.example.com) State HIBERNATE
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_core_state_machine.c:662 (sofia/622112345678-external/0817123456) State HIBERNATE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.com) Running State Change CS_HIBERNATE (Cur 2 Tot 57)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/101@pbx.example.com) State EXECUTE going to sleep
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_core_state_machine.c:581 (sofia/622112345678-external/0817123456) Running State Change CS_HIBERNATE (Cur 2 Tot 57)
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_ivr_bridge.c:1588 (sofia/622112345678-external/0817123456) State Change CS_CONSUME_MEDIA -> CS_HIBERNATE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_ivr_bridge.c:1587 (sofia/internal/101@pbx.example.com) State Change CS_EXECUTE -> CS_HIBERNATE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.415684 49.03% [DEBUG] sofia.c:7493 Channel sofia/internal/101@pbx.example.com entering state [early][183]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_channel.c:3585 (sofia/internal/101@pbx.example.com) Callstate Change RINGING -> EARLY
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.415684 49.03% [NOTICE] mod_sofia.c:2610 Pre-Answer sofia/internal/101@pbx.example.com!
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.415684 49.03% [INFO] switch_ivr.c:825 Sending early media
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_ivr_originate.c:3913 Originate Resulted in Success: [sofia/622112345678-external/0817123456] Peer UUID: 0008038c-7722-43e9-b01a-92c9458b259c
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:02.415684 49.03% [DEBUG] switch_channel.c:3585 (sofia/622112345678-external/0817123456) Callstate Change DOWN -> EARLY
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:02.415684 49.03% [NOTICE] sofia.c:7506 Pre-Answer sofia/622112345678-external/0817123456!
0008038c-7722-43e9-b01a-92c9458b259c
0008038c-7722-43e9-b01a-92c9458b259c a=fmtp:101 0-15
0008038c-7722-43e9-b01a-92c9458b259c a=rtpmap:101 telephone-event/8000
0008038c-7722-43e9-b01a-92c9458b259c a=rtpmap:8 PCMA/8000
0008038c-7722-43e9-b01a-92c9458b259c m=audio 10608 RTP/AVP 8 101
0008038c-7722-43e9-b01a-92c9458b259c t=0 0
0008038c-7722-43e9-b01a-92c9458b259c c=IN IP4 43.1.2.31.2.3245.185.3
0008038c-7722-43e9-b01a-92c9458b259c s=-
0008038c-7722-43e9-b01a-92c9458b259c o=GANG 744040838 744040839 IN IP4 43.1.2.31.2.3245.185.3
0008038c-7722-43e9-b01a-92c9458b259c v=0
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:02.415684 49.03% [DEBUG] sofia.c:7503 Remote SDP:
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:02.415684 49.03% [DEBUG] sofia.c:7493 Channel sofia/622112345678-external/0817123456 entering state [proceeding][183]
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:659 (sofia/622112345678-external/0817123456) State CONSUME_MEDIA going to sleep
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:659 (sofia/622112345678-external/0817123456) State CONSUME_MEDIA
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:581 (sofia/622112345678-external/0817123456) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 57)
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:640 (sofia/622112345678-external/0817123456) State ROUTING going to sleep
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_ivr_originate.c:67 (sofia/622112345678-external/0817123456) State Change CS_ROUTING -> CS_CONSUME_MEDIA
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_sofia.c:158 sofia/622112345678-external/0817123456 SOFIA ROUTING
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:640 (sofia/622112345678-external/0817123456) State ROUTING
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] sofia.c:7493 Channel sofia/622112345678-external/0817123456 entering state [calling][0]
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:581 (sofia/622112345678-external/0817123456) Running State Change CS_ROUTING (Cur 2 Tot 57)
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:624 (sofia/622112345678-external/0817123456) State INIT going to sleep
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:48 (sofia/622112345678-external/0817123456) State Change CS_INIT -> CS_ROUTING
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:40 sofia/622112345678-external/0817123456 Standard INIT
0008038c-7722-43e9-b01a-92c9458b259c
0008038c-7722-43e9-b01a-92c9458b259c a=ssrc:1031348853 cname:6f7755d52abb16b6
0008038c-7722-43e9-b01a-92c9458b259c a=rtcp:4001 IN IP4 100.96.1.2
0008038c-7722-43e9-b01a-92c9458b259c a=fmtp:101 0-16
0008038c-7722-43e9-b01a-92c9458b259c a=rtpmap:101 telephone-event/8000
0008038c-7722-43e9-b01a-92c9458b259c a=rtpmap:0 PCMU/8000
0008038c-7722-43e9-b01a-92c9458b259c a=rtpmap:8 PCMA/8000
0008038c-7722-43e9-b01a-92c9458b259c b=TIAS:64000
0008038c-7722-43e9-b01a-92c9458b259c c=IN IP4 100.96.1.2
0008038c-7722-43e9-b01a-92c9458b259c m=audio 4000 RTP/AVP 8 0 101
0008038c-7722-43e9-b01a-92c9458b259c a=X-nat:0
0008038c-7722-43e9-b01a-92c9458b259c t=0 0
0008038c-7722-43e9-b01a-92c9458b259c b=AS:84
0008038c-7722-43e9-b01a-92c9458b259c s=pjmedia
0008038c-7722-43e9-b01a-92c9458b259c o=- 3917058422 3917058422 IN IP4 100.96.1.2
0008038c-7722-43e9-b01a-92c9458b259c v=0
0008038c-7722-43e9-b01a-92c9458b259c Local SDP:
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] sofia_glue.c:1662 sofia/622112345678-external/0817123456 sending invite version: 1.10.11 -release 64bit
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [INFO] sofia_glue.c:1659 sofia/622112345678-external/0817123456 sending invite call-id: (null)
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_sofia.c:97 sofia/622112345678-external/0817123456 SOFIA INIT
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:624 (sofia/622112345678-external/0817123456) State INIT
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:581 (sofia/622112345678-external/0817123456) Running State Change CS_INIT (Cur 2 Tot 57)
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_sofia.c:5110 (sofia/622112345678-external/0817123456) State Change CS_NEW -> CS_INIT
0008038c-7722-43e9-b01a-92c9458b259c 2024-02-16 08:47:01.495689 49.33% [NOTICE] switch_channel.c:1142 New Channel sofia/622112345678-external/0817123456 [0008038c-7722-43e9-b01a-92c9458b259c]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_ivr_originate.c:2301 Parsing global variables
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_channel.c:1288 sofia/internal/101@pbx.example.com EXPORTING[export_vars] [origination_callee_id_name]=[0817123456] to event
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_channel.c:1288 sofia/internal/101@pbx.example.com EXPORTING[export_vars] [call_direction]=[outbound] to event
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_channel.c:1288 sofia/internal/101@pbx.example.com EXPORTING[export_vars] [call_direction]=[outbound] to event
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_channel.c:1288 sofia/internal/101@pbx.example.com EXPORTING[export_vars] [domain_uuid]=[76a434a2-35a6-46cc-85bd-e1911c1b7938] to event
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_channel.c:1288 sofia/internal/101@pbx.example.com EXPORTING[export_vars] [domain_name]=[pbx.example.com] to event
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com bridge(sofia/gateway/80a08481-c8c1-4063-b9d2-c46e30400a57/0817123456)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [bypass_media]=[true]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(bypass_media=true)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [continue_on_fail]=[1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(continue_on_fail=1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [callee_id_number]=[0817123456]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(callee_id_number=0817123456)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [ignore_display_updates]=[true]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(ignore_display_updates=true)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [inherit_codec]=[true]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(inherit_codec=true)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [effective_caller_id_number]=[UNDEF]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(effective_caller_id_number=)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [effective_caller_id_name]=[UNDEF]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(effective_caller_id_name=)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [hangup_after_bridge]=[true]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(hangup_after_bridge=true)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1816 UNSET [call_timeout]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com unset(call_timeout)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com hash(insert/pbx.example.com-last_dial/101/0817123456)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [origination_callee_id_name]=[0817123456]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com export(origination_callee_id_name=0817123456)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [RFC2822_DATE]=[Fri, 16 Feb 2024 08:47:01 +0800]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(RFC2822_DATE=Fri, 16 Feb 2024 08:47:01 +0800)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [caller_id_number]=[101]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(caller_id_number=101)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:323 sofia/internal/101@pbx.example.com Standard EXECUTE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_sofia.c:213 sofia/internal/101@pbx.example.com SOFIA EXECUTE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/101@pbx.example.com) State EXECUTE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.com) Running State Change CS_EXECUTE (Cur 1 Tot 56)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/101@pbx.example.com) State ROUTING going to sleep
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/101@pbx.example.com) State Change CS_ROUTING -> CS_EXECUTE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action bridge(sofia/gateway/80a08481-c8c1-4063-b9d2-c46e30400a57/0817123456)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(bypass_media=true)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(continue_on_fail=1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(callee_id_number=0817123456)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(ignore_display_updates=true)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(inherit_codec=true)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(effective_caller_id_number=${outbound_caller_id_number})
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(effective_caller_id_name=${outbound_caller_id_name})
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(hangup_after_bridge=true)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action unset(call_timeout)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[outbound]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com export(call_direction=outbound)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action export(call_direction=outbound) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [622112345678-Out] destination_number(0817123456) =~ /^(?:\+?62|0)(\d+)$/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [622112345678-Out] ${user_exists}(false) =~ /false/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->622112345678-Out] continue=false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_hold_music] ${user_exists}(false) =~ /true/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->user_hold_music] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [outbound_caller_id_number]=[UNDEF]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(outbound_caller_id_number=)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(outbound_caller_id_number=${default_outbound_caller_id_number}) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [default_caller_id] ${outbound_caller_id_number}() =~ /^$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [default_caller_id] ${loopback_leg}() =~ /^$/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [outbound_caller_id_name]=[UNDEF]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(outbound_caller_id_name=)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(outbound_caller_id_name=${default_outbound_caller_id_name}) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [default_caller_id] ${outbound_caller_id_name}() =~ /^$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [default_caller_id] ${loopback_leg}() =~ /^$/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [emergency_caller_id_number]=[UNDEF]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(emergency_caller_id_number=)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [emergency_caller_id_name]=[UNDEF]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(emergency_caller_id_name=)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [default_caller_id] ${emergency_caller_id_name}() =~ /^$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->default_caller_id] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [speed_dial] destination_number(0817123456) =~ /^\*0(.*)$/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->speed_dial] continue=false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [redial] () =~ // break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [redial] destination_number(0817123456) =~ /^(redial|\*870)$/ break=on-true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->redial] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [rtp_has_crypto] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->rtp_has_crypto] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^local$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [user_record] ${call_direction}(outbound) =~ /^outbound$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^inbound$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [from_user_record]=[UNDEF]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(from_user_record=)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^local$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [user_record] ${call_direction}(outbound) =~ /^outbound$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^inbound$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->user_record] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [call-direction] ${call_direction}(outbound) =~ /^$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->call-direction] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->is_loopback] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->clear_sip_auto_answer] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[outbound]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com export(call_direction=outbound)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action export(call_direction=outbound) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [call_direction-outbound] destination_number(0817123456) =~ /^(?:\+?62|0)(\d+)$/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [call_direction-outbound] ${call_direction}() =~ /^$/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [call_direction-outbound] ${user_exists}(false) =~ /false/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->call_direction-outbound] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [operator]=[1000]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(operator=1000)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(operator=1000) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action export(origination_callee_id_name=${caller_destination})
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [domain-variables] () =~ // break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->domain-variables] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [global-variables] () =~ // break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->global-variables] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(caller_id_number=${caller_id_number})
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [caller_id_name]=[101]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(caller_id_name=101)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(caller_id_name=${caller_id_name}) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [caller_destination]=[0817123456]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(caller_destination=0817123456)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(caller_destination=${destination_number}) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->caller-details] continue=true
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [from_user_exists]=[true]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(from_user_exists=true)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.495689 49.33% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.com [user_exists]=[false]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 EXECUTE [depth=0] sofia/internal/101@pbx.example.com set(user_exists=false)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (PASS) [user_exists] () =~ // break=on-false
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 Dialplan: sofia/internal/101@pbx.example.com parsing [pbx.example.com->user_exists] continue=true
2024-02-16 08:47:01.475690 49.33% [NOTICE] switch_cpp.cpp:1466 [xml_handler] multiple key:dialplan:pbx.example.com
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [INFO] mod_dialplan_xml.c:639 Processing 101 <101>->0817123456 in context pbx.example.com
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] switch_core_state_machine.c:230 sofia/internal/101@pbx.example.com Standard ROUTING
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] mod_sofia.c:158 sofia/internal/101@pbx.example.com SOFIA ROUTING
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/101@pbx.example.com) State ROUTING
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] switch_channel.c:2399 (sofia/internal/101@pbx.example.com) Callstate Change DOWN -> RINGING
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.com) Running State Change CS_ROUTING (Cur 1 Tot 56)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/101@pbx.example.com) State INIT going to sleep
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/101@pbx.example.com) State Change CS_INIT -> CS_ROUTING
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] switch_core_state_machine.c:40 sofia/internal/101@pbx.example.com Standard INIT
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] mod_sofia.c:97 sofia/internal/101@pbx.example.com SOFIA INIT
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/101@pbx.example.com) State INIT
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.com) Running State Change CS_INIT (Cur 1 Tot 56)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] sofia.c:7906 (sofia/internal/101@pbx.example.com) State Change CS_NEW -> CS_INIT
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 a=ssrc:1031348853 cname:6f7755d52abb16b6
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 a=rtcp:4001 IN IP4 100.96.1.2
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 a=fmtp:101 0-16
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 a=rtpmap:101 telephone-event/8000
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 a=rtpmap:0 PCMU/8000
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 a=rtpmap:8 PCMA/8000
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 b=TIAS:64000
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 c=IN IP4 100.96.1.2
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 m=audio 4000 RTP/AVP 8 0 101
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 a=X-nat:0
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 t=0 0
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 b=AS:84
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 s=pjmedia
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 o=- 3917058422 3917058422 IN IP4 100.96.1.2
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 v=0
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] sofia.c:7503 Remote SDP:
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] sofia.c:7493 Channel sofia/internal/101@pbx.example.com entering state [received][100]
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.475690 49.33% [DEBUG] sofia.c:11674 Setting NAT mode based on via received
2024-02-16 08:47:01.455682 49.33% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 149.1.2.3:0.
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.455682 49.33% [INFO] sofia.c:10459 sofia/internal/101@pbx.example.com receiving invite from 149.1.2.3:58043 version: 1.10.11 -release 64bit call-id: 0fa5e540a42f45a9bd6520ac04d98162
2024-02-16 08:47:01.455682 49.33% [DEBUG] sofia.c:2532 Re-attaching to session 8bf7b9c9-8375-40cc-9050-02e5a5a49bd1
2024-02-16 08:47:01.375681 49.33% [DEBUG] sofia.c:2419 detaching session 8bf7b9c9-8375-40cc-9050-02e5a5a49bd1
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.375681 49.33% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/101@pbx.example.com) State NEW
2024-02-16 08:47:01.375681 49.33% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 149.1.2.3:0.
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.375681 49.33% [INFO] sofia.c:10459 sofia/internal/101@pbx.example.com receiving invite from 149.1.2.3:58043 version: 1.10.11 -release 64bit call-id: 0fa5e540a42f45a9bd6520ac04d98162
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.375681 49.33% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.com) Running State Change CS_NEW (Cur 1 Tot 56)
8bf7b9c9-8375-40cc-9050-02e5a5a49bd1 2024-02-16 08:47:01.375681 49.33% [NOTICE] switch_channel.c:1142 New Channel sofia/internal/101@pbx.example.com [8bf7b9c9-8375-40cc-9050-02e5a5a49bd1]
 
Last edited:

voipBull

Member
Dec 3, 2023
96
21
8
@Win From the logs looks like its your endpoint (whatever has extension 101 on it) is not sending ACK to the 200 OK that FusionPBX is sending it. Take a look at the CALL LEG A SIP messages (between endpoint and FusionPBX).
 

Win

Member
Feb 12, 2024
49
2
8
I set sofia global siptrace on

== paste after answered == 101 sent BYE with Reason: SIP;cause=408;text="ACK Timeout"

2024-02-16 11:36:51.761364 99.20% [NOTICE] switch_ivr.c:820 Channel [sofia/internal/101@pbx.example.co.id] has been answered
2024-02-16 11:36:51.761364 99.20% [DEBUG] switch_channel.c:3912 (sofia/internal/101@pbx.example.co.id) Callstate Change EARLY -> ACTIVE
2024-02-16 11:36:51.761364 99.20% [DEBUG] sofia.c:7493 Channel sofia/internal/101@pbx.example.co.id entering state [completed][200]
send 1083 bytes to udp/[182.253.56.161]:5590 at 11:36:52.270958:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjbc0d0981c01b4554ac2f0dccda5b19a6;rport=5590
From: <sip:101@pbx.example.co.id>;tag=9b574fa075c64afeb8987c3b8f981bb4
To: <sip:0817145779@pbx.example.co.id>;tag=XcX15r3ZeaZyF
Call-ID: baf53b0e74934803861f18a0649cac04
CSeq: 25504 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no
v=0
o=GANG 744172228 744172229 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10016 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
send 1083 bytes to udp/[182.253.56.161]:5590 at 11:36:53.271049:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjbc0d0981c01b4554ac2f0dccda5b19a6;rport=5590
From: <sip:101@pbx.example.co.id>;tag=9b574fa075c64afeb8987c3b8f981bb4
To: <sip:0817145779@pbx.example.co.id>;tag=XcX15r3ZeaZyF
Call-ID: baf53b0e74934803861f18a0649cac04
CSeq: 25504 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no
v=0
o=GANG 744172228 744172229 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10016 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
send 1083 bytes to udp/[182.253.56.161]:5590 at 11:36:55.272065:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjbc0d0981c01b4554ac2f0dccda5b19a6;rport=5590
From: <sip:101@pbx.example.co.id>;tag=9b574fa075c64afeb8987c3b8f981bb4
To: <sip:0817145779@pbx.example.co.id>;tag=XcX15r3ZeaZyF
Call-ID: baf53b0e74934803861f18a0649cac04
CSeq: 25504 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no
v=0
o=GANG 744172228 744172229 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10016 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
send 1083 bytes to udp/[182.253.56.161]:5590 at 11:36:59.272113:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjbc0d0981c01b4554ac2f0dccda5b19a6;rport=5590
From: <sip:101@pbx.example.co.id>;tag=9b574fa075c64afeb8987c3b8f981bb4
To: <sip:0817145779@pbx.example.co.id>;tag=XcX15r3ZeaZyF
Call-ID: baf53b0e74934803861f18a0649cac04
CSeq: 25504 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no
v=0
o=GANG 744172228 744172229 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10016 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
send 1083 bytes to udp/[182.253.56.161]:5590 at 11:37:03.272158:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjbc0d0981c01b4554ac2f0dccda5b19a6;rport=5590
From: <sip:101@pbx.example.co.id>;tag=9b574fa075c64afeb8987c3b8f981bb4
To: <sip:0817145779@pbx.example.co.id>;tag=XcX15r3ZeaZyF
Call-ID: baf53b0e74934803861f18a0649cac04
CSeq: 25504 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no
v=0
o=GANG 744172228 744172229 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10016 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
send 1083 bytes to udp/[182.253.56.161]:5590 at 11:37:07.272455:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjbc0d0981c01b4554ac2f0dccda5b19a6;rport=5590
From: <sip:101@pbx.example.co.id>;tag=9b574fa075c64afeb8987c3b8f981bb4
To: <sip:0817145779@pbx.example.co.id>;tag=XcX15r3ZeaZyF
Call-ID: baf53b0e74934803861f18a0649cac04
CSeq: 25504 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no
v=0
o=GANG 744172228 744172229 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10016 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
send 1083 bytes to udp/[182.253.56.161]:5590 at 11:37:11.273496:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjbc0d0981c01b4554ac2f0dccda5b19a6;rport=5590
From: <sip:101@pbx.example.co.id>;tag=9b574fa075c64afeb8987c3b8f981bb4
To: <sip:0817145779@pbx.example.co.id>;tag=XcX15r3ZeaZyF
Call-ID: baf53b0e74934803861f18a0649cac04
CSeq: 25504 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no
v=0
o=GANG 744172228 744172229 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10016 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
send 1083 bytes to udp/[182.253.56.161]:5590 at 11:37:15.274535:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjbc0d0981c01b4554ac2f0dccda5b19a6;rport=5590
From: <sip:101@pbx.example.co.id>;tag=9b574fa075c64afeb8987c3b8f981bb4
To: <sip:0817145779@pbx.example.co.id>;tag=XcX15r3ZeaZyF
Call-ID: baf53b0e74934803861f18a0649cac04
CSeq: 25504 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no
v=0
o=GANG 744172228 744172229 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10016 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
send 1083 bytes to udp/[182.253.56.161]:5590 at 11:37:19.274581:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjbc0d0981c01b4554ac2f0dccda5b19a6;rport=5590
From: <sip:101@pbx.example.co.id>;tag=9b574fa075c64afeb8987c3b8f981bb4
To: <sip:0817145779@pbx.example.co.id>;tag=XcX15r3ZeaZyF
Call-ID: baf53b0e74934803861f18a0649cac04
CSeq: 25504 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no
v=0
o=GANG 744172228 744172229 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10016 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
send 1083 bytes to udp/[182.253.56.161]:5590 at 11:37:23.275366:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjbc0d0981c01b4554ac2f0dccda5b19a6;rport=5590
From: <sip:101@pbx.example.co.id>;tag=9b574fa075c64afeb8987c3b8f981bb4
To: <sip:0817145779@pbx.example.co.id>;tag=XcX15r3ZeaZyF
Call-ID: baf53b0e74934803861f18a0649cac04
CSeq: 25504 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no
v=0
o=GANG 744172228 744172229 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10016 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
send 611 bytes to udp/[182.253.56.161]:5590 at 11:37:23.771449:
------------------------------------------------------------------------
BYE sip:101@182.253.56.161:5590;ob SIP/2.0
Via: SIP/2.0/UDP 172.31.203.210;rport;branch=z9hG4bKNK0U15aaNN8Uc
Max-Forwards: 70
From: <sip:0817145779@pbx.example.co.id>;tag=XcX15r3ZeaZyF
To: <sip:101@pbx.example.co.id>;tag=9b574fa075c64afeb8987c3b8f981bb4
Call-ID: baf53b0e74934803861f18a0649cac04
CSeq: 79473529 BYE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Reason: SIP;cause=408;text="ACK Timeout"
Content-Length: 0

2024-02-16 11:37:23.761361 99.20% [DEBUG] sofia.c:7493 Channel sofia/internal/101@pbx.example.co.id entering state [terminating][0]
2024-02-16 11:37:23.761361 99.20% [NOTICE] sofia.c:8735 Hangup sofia/internal/101@pbx.example.co.id [CS_HIBERNATE] [MANDATORY_IE_MISSING]
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_ivr_bridge.c:1334 sofia/internal/101@pbx.example.co.id skip receive message [UNBRIDGE] (channel is hungup already)
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.co.id) Running State Change CS_HANGUP (Cur 2 Tot 4)
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/101@pbx.example.co.id) Callstate Change ACTIVE -> HANGUP
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/101@pbx.example.co.id) State HANGUP
2024-02-16 11:37:23.761361 99.20% [DEBUG] mod_sofia.c:469 Channel sofia/internal/101@pbx.example.co.id hanging up, cause: MANDATORY_IE_MISSING
2024-02-16 11:37:23.761361 99.20% [NOTICE] switch_ivr_bridge.c:1473 Hangup sofia/622131180035-external/0817145779 [CS_HIBERNATE] [MANDATORY_IE_MISSING]
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:59 sofia/internal/101@pbx.example.co.id Standard HANGUP, cause: MANDATORY_IE_MISSING
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/101@pbx.example.co.id) State HANGUP going to sleep
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/101@pbx.example.co.id) State Change CS_HANGUP -> CS_REPORTING
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_ivr_bridge.c:1334 sofia/622131180035-external/0817145779 skip receive message [UNBRIDGE] (channel is hungup already)
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:581 (sofia/622131180035-external/0817145779) Running State Change CS_HANGUP (Cur 2 Tot 4)
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.co.id) Running State Change CS_REPORTING (Cur 2 Tot 4)
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:844 (sofia/622131180035-external/0817145779) Callstate Change ACTIVE -> HANGUP
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:846 (sofia/622131180035-external/0817145779) State HANGUP
2024-02-16 11:37:23.761361 99.20% [DEBUG] mod_sofia.c:469 Channel sofia/622131180035-external/0817145779 hanging up, cause: MANDATORY_IE_MISSING
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/101@pbx.example.co.id) State REPORTING
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:168 sofia/internal/101@pbx.example.co.id Standard REPORTING, cause: MANDATORY_IE_MISSING
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/101@pbx.example.co.id) State REPORTING going to sleep
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/101@pbx.example.co.id) State Change CS_REPORTING -> CS_DESTROY
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_session.c:1744 Session 3 (sofia/internal/101@pbx.example.co.id) Locked, Waiting on external entities
2024-02-16 11:37:23.761361 99.20% [NOTICE] switch_core_session.c:1762 Session 3 (sofia/internal/101@pbx.example.co.id) Ended
2024-02-16 11:37:23.761361 99.20% [NOTICE] switch_core_session.c:1766 Close Channel sofia/internal/101@pbx.example.co.id [CS_DESTROY]
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/101@pbx.example.co.id) Running State Change CS_DESTROY (Cur 1 Tot 4)
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/101@pbx.example.co.id) State DESTROY
2024-02-16 11:37:23.761361 99.20% [DEBUG] mod_sofia.c:380 sofia/internal/101@pbx.example.co.id SOFIA DESTROY
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:175 sofia/internal/101@pbx.example.co.id Standard DESTROY
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/101@pbx.example.co.id) State DESTROY going to sleep
2024-02-16 11:37:23.761361 99.20% [DEBUG] mod_sofia.c:523 Sending BYE to sofia/622131180035-external/0817145779
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:59 sofia/622131180035-external/0817145779 Standard HANGUP, cause: MANDATORY_IE_MISSING
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:846 (sofia/622131180035-external/0817145779) State HANGUP going to sleep
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:616 (sofia/622131180035-external/0817145779) State Change CS_HANGUP -> CS_REPORTING
2024-02-16 11:37:23.761361 99.20% [DEBUG] switch_core_state_machine.c:581 (sofia/622131180035-external/0817145779) Running State Change CS_REPORTING (Cur 1 Tot 4)

pbx> /exit
 
Last edited:

voipBull

Member
Dec 3, 2023
96
21
8
That capture just proved what I said above. See those 10 repeated 200 OK's being sent to your endpoint udp/[182.253.56.161]:5590 but no ACK back. Need to see all of this call leg starting from the first INVITE.
 

Win

Member
Feb 12, 2024
49
2
8
Hi @voipBull

here it is:

[This app Best viewed at 160x60 or more..]
+OK log level [7]
freeswitch@pbx> sofia global siptrace on
+OK Global siptrace on
recv 979 bytes from udp/[182.253.56.161]:5590 at 12:34:15.755587:
------------------------------------------------------------------------
INVITE sip:0817145779@pbx.example.co.id SIP/2.0
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPj9430826bc2d54f78967fba357fb2b223;rport
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>
CSeq: 3361 INVITE
Max-Forwards: 70
Contact: <sip:101@182.253.56.161:5590;ob>
Allow: PRACK,INVITE,ACK,BYE,CANCEL,UPDATE,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE,OPTIONS
Supported: replaces,100rel,timer,norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: MicroSIP/3.20.7
Content-Length: 346
Content-Type: application/sdp

v=0
o=- 3917072056 3917072056 IN IP4 182.253.56.161
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 32542 RTP/AVP 8 0 101
c=IN IP4 182.253.56.161
b=TIAS:64000
a=rtcp:4027 IN IP4 192.168.18.14
a=sendrecv
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ssrc:1798054136 cname:0b750d9b11c8218d

2024-02-16 12:34:15.741366 99.53% [NOTICE] switch_channel.c:1142 New Channel sofia/internal/101@pbx.example.co.id [6c6ce6c5-9d26-4900-8214-1755cf8bb8da]
2024-02-16 12:34:15.741366 99.53% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.co.id) Running State Change CS_NEW (Cur 1 Tot 5)
2024-02-16 12:34:15.741366 99.53% [INFO] sofia.c:10459 sofia/internal/101@pbx.example.co.id receiving invite from 182.253.56.161:5590 version: 1.10.11 -release 64bit call-id: 2edb4ebbfe2240beb5399213a39b5652
2024-02-16 12:34:15.741366 99.53% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 182.253.56.161:0.
2024-02-16 12:34:15.741366 99.53% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/101@pbx.example.co.id) State NEW
send 844 bytes to udp/[182.253.56.161]:5590 at 12:34:15.756279:
------------------------------------------------------------------------
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPj9430826bc2d54f78967fba357fb2b223;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=mv2Ue76gcQZca
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3361 INVITE
User-Agent: FreeSWITCH
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Proxy-Authenticate: Digest realm="pbx.example.co.id", nonce="bc291a5e-1a60-424e-a2c4-6684f1314191", algorithm=MD5, qop="auth"
Content-Length: 0


2024-02-16 12:34:15.741366 99.53% [DEBUG] sofia.c:2419 detaching session 6c6ce6c5-9d26-4900-8214-1755cf8bb8da
recv 373 bytes from udp/[182.253.56.161]:5590 at 12:34:15.762982:
------------------------------------------------------------------------
ACK sip:0817145779@pbx.example.co.id SIP/2.0
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPj9430826bc2d54f78967fba357fb2b223;rport
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=mv2Ue76gcQZca
CSeq: 3361 ACK
Max-Forwards: 70
Content-Length: 0


recv 1258 bytes from udp/[182.253.56.161]:5590 at 12:34:15.764122:
------------------------------------------------------------------------
INVITE sip:0817145779@pbx.example.co.id SIP/2.0
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>
CSeq: 3362 INVITE
Max-Forwards: 70
Contact: <sip:101@182.253.56.161:5590;ob>
Allow: PRACK,INVITE,ACK,BYE,CANCEL,UPDATE,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE,OPTIONS
Supported: replaces,100rel,timer,norefersub
Session-Expires: 1800
Min-SE: 90
User-Agent: MicroSIP/3.20.7
Proxy-Authorization: Digest username="101",realm="pbx.example.co.id",nonce="bc291a5e-1a60-424e-a2c4-6684f1314191",uri="sip:0817145779@pbx.example.co.id",response="f1b44158797abdb6196dbd6bcc9cb543",algorithm=MD5,cnonce="cf58de4e7f514b4b8e8bde3714731c62",qop=auth,nc=00000001
Content-Length: 346
Content-Type: application/sdp

v=0
o=- 3917072056 3917072056 IN IP4 182.253.56.161
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 32542 RTP/AVP 8 0 101
c=IN IP4 182.253.56.161
b=TIAS:64000
a=rtcp:4027 IN IP4 192.168.18.14
a=sendrecv
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ssrc:1798054136 cname:0b750d9b11c8218d

2024-02-16 12:34:15.761363 99.53% [DEBUG] sofia.c:2532 Re-attaching to session 6c6ce6c5-9d26-4900-8214-1755cf8bb8da
2024-02-16 12:34:15.761363 99.53% [INFO] sofia.c:10459 sofia/internal/101@pbx.example.co.id receiving invite from 182.253.56.161:5590 version: 1.10.11 -release 64bit call-id: 2edb4ebbfe2240beb5399213a39b5652
2024-02-16 12:34:15.761363 99.53% [DEBUG] sofia.c:10553 verifying acl "providers" for ip/port 182.253.56.161:0.
2024-02-16 12:34:15.761363 99.53% [DEBUG] sofia.c:7493 Channel sofia/internal/101@pbx.example.co.id entering state [received][100]
2024-02-16 12:34:15.761363 99.53% [DEBUG] sofia.c:7503 Remote SDP:
v=0
o=- 3917072056 3917072056 IN IP4 182.253.56.161
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 32542 RTP/AVP 8 0 101
c=IN IP4 182.253.56.161
b=TIAS:64000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp:4027 IN IP4 192.168.18.14
a=ssrc:1798054136 cname:0b750d9b11c8218d

2024-02-16 12:34:15.761363 99.53% [DEBUG] sofia.c:7906 (sofia/internal/101@pbx.example.co.id) State Change CS_NEW -> CS_INIT
2024-02-16 12:34:15.761363 99.53% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.co.id) Running State Change CS_INIT (Cur 1 Tot 5)
2024-02-16 12:34:15.761363 99.53% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/101@pbx.example.co.id) State INIT
2024-02-16 12:34:15.761363 99.53% [DEBUG] mod_sofia.c:97 sofia/internal/101@pbx.example.co.id SOFIA INIT
2024-02-16 12:34:15.761363 99.53% [DEBUG] switch_core_state_machine.c:40 sofia/internal/101@pbx.example.co.id Standard INIT
2024-02-16 12:34:15.761363 99.53% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/101@pbx.example.co.id) State Change CS_INIT -> CS_ROUTING
2024-02-16 12:34:15.761363 99.53% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/101@pbx.example.co.id) State INIT going to sleep
2024-02-16 12:34:15.761363 99.53% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.co.id) Running State Change CS_ROUTING (Cur 1 Tot 5)
2024-02-16 12:34:15.761363 99.53% [DEBUG] switch_channel.c:2399 (sofia/internal/101@pbx.example.co.id) Callstate Change DOWN -> RINGING
2024-02-16 12:34:15.761363 99.53% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/101@pbx.example.co.id) State ROUTING
2024-02-16 12:34:15.761363 99.53% [DEBUG] mod_sofia.c:158 sofia/internal/101@pbx.example.co.id SOFIA ROUTING
2024-02-16 12:34:15.761363 99.53% [DEBUG] switch_core_state_machine.c:230 sofia/internal/101@pbx.example.co.id Standard ROUTING
2024-02-16 12:34:15.761363 99.53% [INFO] mod_dialplan_xml.c:639 Processing 101 <101>->0817145779 in context pbx.example.co.id
send 341 bytes to udp/[182.253.56.161]:5590 at 12:34:15.779425:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
User-Agent: FreeSWITCH
Content-Length: 0


2024-02-16 12:34:15.781381 99.53% [NOTICE] switch_cpp.cpp:1466 [xml_handler] multiple key:dialplan:pbx.example.co.id
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->user_exists] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(user_exists=false)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [user_exists]=[false]
Dialplan: sofia/internal/101@pbx.example.co.id Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(from_user_exists=true)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [from_user_exists]=[true]
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->caller-details] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Action set(caller_destination=${destination_number}) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(caller_destination=0817145779)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [caller_destination]=[0817145779]
Dialplan: sofia/internal/101@pbx.example.co.id Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(caller_id_name=101)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [caller_id_name]=[101]
Dialplan: sofia/internal/101@pbx.example.co.id Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->global-variables] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [global-variables] () =~ // break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->domain-variables] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [domain-variables] () =~ // break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Action export(origination_callee_id_name=${caller_destination})
Dialplan: sofia/internal/101@pbx.example.co.id Action set(operator=1000) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(operator=1000)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [operator]=[1000]
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->call_direction-outbound] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [call_direction-outbound] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [call_direction-outbound] ${call_direction}() =~ /^$/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [call_direction-outbound] destination_number(0817145779) =~ /^(?:\+?62|0)(\d+)$/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Action export(call_direction=outbound) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id export(call_direction=outbound)
2024-02-16 12:34:15.781381 99.53% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[outbound]
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->clear_sip_auto_answer] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->is_loopback] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->call-direction] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [call-direction] ${call_direction}(outbound) =~ /^$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->user_record] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^inbound$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [user_record] ${call_direction}(outbound) =~ /^outbound$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^local$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(from_user_record=)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [from_user_record]=[UNDEF]
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^inbound$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [user_record] ${call_direction}(outbound) =~ /^outbound$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${call_direction}(outbound) =~ /^local$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->rtp_has_crypto] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [rtp_has_crypto] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->redial] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [redial] destination_number(0817145779) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/internal/101@pbx.example.co.id Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->speed_dial] continue=false
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [speed_dial] destination_number(0817145779) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->default_caller_id] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [default_caller_id] ${emergency_caller_id_name}() =~ /^$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(emergency_caller_id_name=)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [emergency_caller_id_name]=[UNDEF]
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(emergency_caller_id_number=)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [emergency_caller_id_number]=[UNDEF]
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [default_caller_id] ${loopback_leg}() =~ /^$/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [default_caller_id] ${outbound_caller_id_name}() =~ /^$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Action set(outbound_caller_id_name=${default_outbound_caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(outbound_caller_id_name=)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [outbound_caller_id_name]=[UNDEF]
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [default_caller_id] ${call_direction}(outbound) =~ /outbound/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [default_caller_id] ${loopback_leg}() =~ /^$/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [default_caller_id] ${outbound_caller_id_number}() =~ /^$/ break=never
Dialplan: sofia/internal/101@pbx.example.co.id Action set(outbound_caller_id_number=${default_outbound_caller_id_number}) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(outbound_caller_id_number=)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [outbound_caller_id_number]=[UNDEF]
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->user_hold_music] continue=true
Dialplan: sofia/internal/101@pbx.example.co.id Regex (FAIL) [user_hold_music] ${user_exists}(false) =~ /true/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id parsing [pbx.example.co.id->622131180035-Out] continue=false
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [622131180035-Out] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Regex (PASS) [622131180035-Out] destination_number(0817145779) =~ /^(?:\+?62|0)(\d+)$/ break=on-false
Dialplan: sofia/internal/101@pbx.example.co.id Action export(call_direction=outbound) INLINE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id export(call_direction=outbound)
2024-02-16 12:34:15.781381 99.53% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[outbound]
Dialplan: sofia/internal/101@pbx.example.co.id Action unset(call_timeout)
Dialplan: sofia/internal/101@pbx.example.co.id Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/101@pbx.example.co.id Action set(effective_caller_id_name=${outbound_caller_id_name})
Dialplan: sofia/internal/101@pbx.example.co.id Action set(effective_caller_id_number=${outbound_caller_id_number})
Dialplan: sofia/internal/101@pbx.example.co.id Action set(inherit_codec=true)
Dialplan: sofia/internal/101@pbx.example.co.id Action set(ignore_display_updates=true)
Dialplan: sofia/internal/101@pbx.example.co.id Action set(callee_id_number=0817145779)
Dialplan: sofia/internal/101@pbx.example.co.id Action set(continue_on_fail=1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809)
Dialplan: sofia/internal/101@pbx.example.co.id Action set(bypass_media=true)
Dialplan: sofia/internal/101@pbx.example.co.id Action bridge(sofia/gateway/80a08481-c8c1-4063-b9d2-c46e30400a57/0817145779)
2024-02-16 12:34:15.781381 99.53% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/101@pbx.example.co.id) State Change CS_ROUTING -> CS_EXECUTE
2024-02-16 12:34:15.781381 99.53% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/101@pbx.example.co.id) State ROUTING going to sleep
2024-02-16 12:34:15.781381 99.53% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.co.id) Running State Change CS_EXECUTE (Cur 1 Tot 5)
2024-02-16 12:34:15.781381 99.53% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/101@pbx.example.co.id) State EXECUTE
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_sofia.c:213 sofia/internal/101@pbx.example.co.id SOFIA EXECUTE
2024-02-16 12:34:15.781381 99.53% [DEBUG] switch_core_state_machine.c:323 sofia/internal/101@pbx.example.co.id Standard EXECUTE
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(caller_id_number=101)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [caller_id_number]=[101]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(RFC2822_DATE=Fri, 16 Feb 2024 12:34:15 +0800)
2024-02-16 12:34:15.781381 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [RFC2822_DATE]=[Fri, 16 Feb 2024 12:34:15 +0800]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id export(origination_callee_id_name=0817145779)
2024-02-16 12:34:15.781381 99.53% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [origination_callee_id_name]=[0817145779]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id hash(insert/pbx.example.co.id-last_dial/101/0817145779)
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id unset(call_timeout)
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_dptools.c:1816 UNSET [call_timeout]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(hangup_after_bridge=true)
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(effective_caller_id_name=)
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [effective_caller_id_name]=[UNDEF]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(effective_caller_id_number=)
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [effective_caller_id_number]=[UNDEF]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(inherit_codec=true)
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [inherit_codec]=[true]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(ignore_display_updates=true)
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [ignore_display_updates]=[true]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(callee_id_number=0817145779)
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [callee_id_number]=[0817145779]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(continue_on_fail=1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809)
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [continue_on_fail]=[1,2,3,6,18,21,27,28,31,34,38,41,42,44,58,88,111,403,501,602,607,809]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id set(bypass_media=true)
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_dptools.c:1671 SET sofia/internal/101@pbx.example.co.id [bypass_media]=[true]
EXECUTE [depth=0] sofia/internal/101@pbx.example.co.id bridge(sofia/gateway/80a08481-c8c1-4063-b9d2-c46e30400a57/0817145779)
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_channel.c:1288 sofia/internal/101@pbx.example.co.id EXPORTING[export_vars] [domain_name]=[pbx.example.co.id] to event
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_channel.c:1288 sofia/internal/101@pbx.example.co.id EXPORTING[export_vars] [domain_uuid]=[76a434a2-35a6-46cc-85bd-e1911c1b7938] to event
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_channel.c:1288 sofia/internal/101@pbx.example.co.id EXPORTING[export_vars] [call_direction]=[outbound] to event
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_channel.c:1288 sofia/internal/101@pbx.example.co.id EXPORTING[export_vars] [call_direction]=[outbound] to event
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_channel.c:1288 sofia/internal/101@pbx.example.co.id EXPORTING[export_vars] [origination_callee_id_name]=[0817145779] to event
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_ivr_originate.c:2301 Parsing global variables
2024-02-16 12:34:15.801376 99.53% [NOTICE] switch_channel.c:1142 New Channel sofia/622131180035-external/0817145779 [0f6290a6-a74d-4bd0-b255-0fca5321f287]
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_sofia.c:5110 (sofia/622131180035-external/0817145779) State Change CS_NEW -> CS_INIT
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_core_state_machine.c:581 (sofia/622131180035-external/0817145779) Running State Change CS_INIT (Cur 2 Tot 6)
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_core_state_machine.c:624 (sofia/622131180035-external/0817145779) State INIT
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_sofia.c:97 sofia/622131180035-external/0817145779 SOFIA INIT
2024-02-16 12:34:15.801376 99.53% [INFO] sofia_glue.c:1659 sofia/622131180035-external/0817145779 sending invite call-id: (null)
2024-02-16 12:34:15.801376 99.53% [DEBUG] sofia_glue.c:1662 sofia/622131180035-external/0817145779 sending invite version: 1.10.11 -release 64bit
Local SDP:
v=0
o=- 3917072056 3917072056 IN IP4 182.253.56.161
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 32542 RTP/AVP 8 0 101
c=IN IP4 182.253.56.161
b=TIAS:64000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp:4027 IN IP4 192.168.18.14
a=ssrc:1798054136 cname:0b750d9b11c8218d

2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_core_state_machine.c:40 sofia/622131180035-external/0817145779 Standard INIT
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_core_state_machine.c:48 (sofia/622131180035-external/0817145779) State Change CS_INIT -> CS_ROUTING
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_core_state_machine.c:624 (sofia/622131180035-external/0817145779) State INIT going to sleep
send 1317 bytes to udp/[43.245.185.3]:5060 at 12:34:15.803509:
------------------------------------------------------------------------
INVITE sip:0817145779@43.245.185.3:5060 SIP/2.0
Via: SIP/2.0/UDP 43.245.185.3:5080;rport;branch=z9hG4bKUtDFKZ9rgrNDQ
Max-Forwards: 69
From: "101" <sip:622131180035@43.245.185.3:5060>;tag=QgyKSZ78DKZXg
To: <sip:0817145779@43.245.185.3:5060>
Call-ID: 7b9795ff-4727-123d-16bf-00163e038571
CSeq: 79475235 INVITE
Contact: <sip:gw+80a08481-c8c1-4063-b9d2-c46e30400a57@43.245.185.3:5080;transport=udp;gw=80a08481-c8c1-4063-b9d2-c46e30400a57>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 334
X-FS-Support: update_display,send_info
Remote-Party-ID: "101" <sip:101@43.245.185.3>;party=calling;screen=yes;privacy=off

v=0
o=- 3917072056 3917072056 IN IP4 182.253.56.161
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 32542 RTP/AVP 8 0 101
c=IN IP4 182.253.56.161
b=TIAS:64000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp:4027 IN IP4 192.168.18.14
a=ssrc:1798054136 cname:0b750d9b11c8218d

2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_core_state_machine.c:581 (sofia/622131180035-external/0817145779) Running State Change CS_ROUTING (Cur 2 Tot 6)
2024-02-16 12:34:15.801376 99.53% [DEBUG] sofia.c:7493 Channel sofia/622131180035-external/0817145779 entering state [calling][0]
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_core_state_machine.c:640 (sofia/622131180035-external/0817145779) State ROUTING
2024-02-16 12:34:15.801376 99.53% [DEBUG] mod_sofia.c:158 sofia/622131180035-external/0817145779 SOFIA ROUTING
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_ivr_originate.c:67 (sofia/622131180035-external/0817145779) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_core_state_machine.c:640 (sofia/622131180035-external/0817145779) State ROUTING going to sleep
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_core_state_machine.c:581 (sofia/622131180035-external/0817145779) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 6)
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_core_state_machine.c:659 (sofia/622131180035-external/0817145779) State CONSUME_MEDIA
2024-02-16 12:34:15.801376 99.53% [DEBUG] switch_core_state_machine.c:659 (sofia/622131180035-external/0817145779) State CONSUME_MEDIA going to sleep
recv 320 bytes from udp/[43.245.185.3]:5060 at 12:34:15.805798:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 43.245.185.3:5080;rport=5080;received=149.129.248.234;branch=z9hG4bKUtDFKZ9rgrNDQ
Call-ID: 7b9795ff-4727-123d-16bf-00163e038571
From: "101" <sip:622131180035@43.245.185.3:5060>;tag=QgyKSZ78DKZXg
To: <sip:0817145779@43.245.185.3:5060>
CSeq: 79475235 INVITE
Content-Length: 0


recv 693 bytes from udp/[43.245.185.3]:5060 at 12:34:16.741625:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 43.245.185.3:5080;rport=5080;received=149.129.248.234;branch=z9hG4bKUtDFKZ9rgrNDQ
Call-ID: 7b9795ff-4727-123d-16bf-00163e038571
From: "101" <sip:622131180035@43.245.185.3:5060>;tag=QgyKSZ78DKZXg
To: <sip:0817145779@43.245.185.3:5060>;tag=6aa2e674-a61a-4e4f-9630-a2ce62ebb063
CSeq: 79475235 INVITE
Contact: <sip:43.245.185.3:5060>
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, OPTIONS
Content-Type: application/sdp
Content-Length: 191

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2024-02-16 12:34:16.741363 99.50% [DEBUG] sofia.c:7493 Channel sofia/622131180035-external/0817145779 entering state [proceeding][183]
2024-02-16 12:34:16.741363 99.50% [DEBUG] sofia.c:7503 Remote SDP:
v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2024-02-16 12:34:16.741363 99.50% [NOTICE] sofia.c:7506 Pre-Answer sofia/622131180035-external/0817145779!
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_channel.c:3585 (sofia/622131180035-external/0817145779) Callstate Change DOWN -> EARLY
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_ivr_originate.c:3913 Originate Resulted in Success: [sofia/622131180035-external/0817145779] Peer UUID: 0f6290a6-a74d-4bd0-b255-0fca5321f287
2024-02-16 12:34:16.741363 99.50% [INFO] switch_ivr.c:825 Sending early media
2024-02-16 12:34:16.741363 99.50% [NOTICE] mod_sofia.c:2610 Pre-Answer sofia/internal/101@pbx.example.co.id!
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_channel.c:3585 (sofia/internal/101@pbx.example.co.id) Callstate Change RINGING -> EARLY
send 1121 bytes to udp/[182.253.56.161]:5590 at 12:34:16.745461:
------------------------------------------------------------------------
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_ivr_bridge.c:1587 (sofia/internal/101@pbx.example.co.id) State Change CS_EXECUTE -> CS_HIBERNATE
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_ivr_bridge.c:1588 (sofia/622131180035-external/0817145779) State Change CS_CONSUME_MEDIA -> CS_HIBERNATE
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_core_state_machine.c:581 (sofia/622131180035-external/0817145779) Running State Change CS_HIBERNATE (Cur 2 Tot 6)
2024-02-16 12:34:16.741363 99.50% [DEBUG] sofia.c:7493 Channel sofia/internal/101@pbx.example.co.id entering state [early][183]
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/101@pbx.example.co.id) State EXECUTE going to sleep
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.co.id) Running State Change CS_HIBERNATE (Cur 2 Tot 6)
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_core_state_machine.c:662 (sofia/622131180035-external/0817145779) State HIBERNATE
2024-02-16 12:34:16.741363 99.50% [DEBUG] mod_sofia.c:195 sofia/622131180035-external/0817145779 SOFIA HIBERNATE
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_core_state_machine.c:417 sofia/622131180035-external/0817145779 Standard HIBERNATE
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_core_state_machine.c:662 (sofia/622131180035-external/0817145779) State HIBERNATE going to sleep
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_core_state_machine.c:662 (sofia/internal/101@pbx.example.co.id) State HIBERNATE
2024-02-16 12:34:16.741363 99.50% [DEBUG] mod_sofia.c:195 sofia/internal/101@pbx.example.co.id SOFIA HIBERNATE
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_core_state_machine.c:417 sofia/internal/101@pbx.example.co.id Standard HIBERNATE
2024-02-16 12:34:16.741363 99.50% [DEBUG] switch_core_state_machine.c:662 (sofia/internal/101@pbx.example.co.id) State HIBERNATE going to sleep
recv 684 bytes from udp/[43.245.185.3]:5060 at 12:34:20.801708:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 43.245.185.3:5080;rport=5080;received=149.129.248.234;branch=z9hG4bKUtDFKZ9rgrNDQ
Call-ID: 7b9795ff-4727-123d-16bf-00163e038571
From: "101" <sip:622131180035@43.245.185.3:5060>;tag=QgyKSZ78DKZXg
To: <sip:0817145779@43.245.185.3:5060>;tag=6aa2e674-a61a-4e4f-9630-a2ce62ebb063
CSeq: 79475235 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, OPTIONS
Contact: <sip:43.245.185.3:5060>
Content-Type: application/sdp
Content-Length: 191

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2024-02-16 12:34:20.801363 99.47% [DEBUG] sofia.c:7493 Channel sofia/622131180035-external/0817145779 entering state [proceeding][180]
2024-02-16 12:34:20.801363 99.47% [DEBUG] sofia.c:7500 Duplicate SDP
v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

recv 684 bytes from udp/[43.245.185.3]:5060 at 12:34:20.924259:
------------------------------------------------------------------------
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 43.245.185.3:5080;rport=5080;received=149.129.248.234;branch=z9hG4bKUtDFKZ9rgrNDQ
Call-ID: 7b9795ff-4727-123d-16bf-00163e038571
From: "101" <sip:622131180035@43.245.185.3:5060>;tag=QgyKSZ78DKZXg
To: <sip:0817145779@43.245.185.3:5060>;tag=6aa2e674-a61a-4e4f-9630-a2ce62ebb063
CSeq: 79475235 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, OPTIONS
Contact: <sip:43.245.185.3:5060>
Content-Type: application/sdp
Content-Length: 191

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2024-02-16 12:34:20.921365 99.47% [DEBUG] sofia.c:7493 Channel sofia/622131180035-external/0817145779 entering state [proceeding][180]
2024-02-16 12:34:20.921365 99.47% [DEBUG] sofia.c:7500 Duplicate SDP
v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

recv 521 bytes from udp/[182.253.56.161]:5590 at 12:34:21.056840:
------------------------------------------------------------------------
REGISTER sip:pbx.example.co.id SIP/2.0
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd9e2cf9228354ad1b4425d18208e570f;rport
Call-ID: ce73fc29479d413caa18d077ecd6f764
From: <sip:101@pbx.example.co.id>;tag=1a2ed1b96eaf42ebbfbb8040129c794e
To: <sip:101@pbx.example.co.id>
CSeq: 31739 REGISTER
Max-Forwards: 70
User-Agent: MicroSIP/3.20.7
Contact: <sip:101@182.253.56.161:5590;ob>
Expires: 300
Allow: PRACK,INVITE,ACK,BYE,CANCEL,UPDATE,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE,OPTIONS
Content-Length: 0


send 625 bytes to udp/[182.253.56.161]:5590 at 12:34:21.057302:
------------------------------------------------------------------------
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd9e2cf9228354ad1b4425d18208e570f;rport=5590
From: <sip:101@pbx.example.co.id>;tag=1a2ed1b96eaf42ebbfbb8040129c794e
To: <sip:101@pbx.example.co.id>;tag=peNDjX8Q68BjH
Call-ID: ce73fc29479d413caa18d077ecd6f764
CSeq: 31739 REGISTER
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
WWW-Authenticate: Digest realm="pbx.example.co.id", nonce="afe000e5-e26e-4401-a8e9-ca5df7683ee3", algorithm=MD5, qop="auth"
Content-Length: 0


recv 783 bytes from udp/[182.253.56.161]:5590 at 12:34:21.064688:
------------------------------------------------------------------------
REGISTER sip:pbx.example.co.id SIP/2.0
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPje0ec861fdac9496e83724cd19793131d;rport
Call-ID: ce73fc29479d413caa18d077ecd6f764
From: <sip:101@pbx.example.co.id>;tag=1a2ed1b96eaf42ebbfbb8040129c794e
To: <sip:101@pbx.example.co.id>
CSeq: 31740 REGISTER
Max-Forwards: 70
User-Agent: MicroSIP/3.20.7
Contact: <sip:101@182.253.56.161:5590;ob>
Expires: 300
Allow: PRACK,INVITE,ACK,BYE,CANCEL,UPDATE,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE,OPTIONS
Authorization: Digest username="101",realm="pbx.example.co.id",nonce="afe000e5-e26e-4401-a8e9-ca5df7683ee3",uri="sip:pbx.example.co.id",response="bcc55baa7e06a619a0a67c3d0a168a57",algorithm=MD5,cnonce="4c95f059c30b45859873c2e0bd0c7ff0",qop=auth,nc=00000001
Content-Length: 0


send 580 bytes to udp/[182.253.56.161]:5590 at 12:34:21.067431:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPje0ec861fdac9496e83724cd19793131d;rport=5590
From: <sip:101@pbx.example.co.id>;tag=1a2ed1b96eaf42ebbfbb8040129c794e
To: <sip:101@pbx.example.co.id>;tag=QQe6KrSU3H24c
Call-ID: ce73fc29479d413caa18d077ecd6f764
CSeq: 31740 REGISTER
Contact: <sip:101@182.253.56.161:5590;ob>;expires=300
Date: Fri, 16 Feb 2024 04:34:21 GMT
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Content-Length: 0


recv 698 bytes from udp/[43.245.185.3]:5060 at 12:34:23.525837:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 43.245.185.3:5080;rport=5080;received=149.129.248.234;branch=z9hG4bKUtDFKZ9rgrNDQ
Call-ID: 7b9795ff-4727-123d-16bf-00163e038571
From: "101" <sip:622131180035@43.245.185.3:5060>;tag=QgyKSZ78DKZXg
To: <sip:0817145779@43.245.185.3:5060>;tag=6aa2e674-a61a-4e4f-9630-a2ce62ebb063
CSeq: 79475235 INVITE
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, OPTIONS
Contact: <sip:43.245.185.3:5060>
Supported: 100rel
Content-Type: application/sdp
Content-Length: 191

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2024-02-16 12:34:23.521365 99.43% [DEBUG] sofia.c:7493 Channel sofia/622131180035-external/0817145779 entering state [completing][200]
2024-02-16 12:34:23.521365 99.43% [DEBUG] sofia.c:7500 Duplicate SDP
v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

send 488 bytes to udp/[43.245.185.3]:5060 at 12:34:23.526707:
------------------------------------------------------------------------
ACK sip:43.245.185.3:5060 SIP/2.0
Via: SIP/2.0/UDP 43.245.185.3:5080;rport;branch=z9hG4bKv367mttvD1B0j
Max-Forwards: 70
From: "101" <sip:622131180035@43.245.185.3:5060>;tag=QgyKSZ78DKZXg
To: <sip:0817145779@43.245.185.3:5060>;tag=6aa2e674-a61a-4e4f-9630-a2ce62ebb063
Call-ID: 7b9795ff-4727-123d-16bf-00163e038571
CSeq: 79475235 ACK
Contact: <sip:gw+80a08481-c8c1-4063-b9d2-c46e30400a57@43.245.185.3:5080;transport=udp;gw=80a08481-c8c1-4063-b9d2-c46e30400a57>
Content-Length: 0


2024-02-16 12:34:23.521365 99.43% [DEBUG] sofia.c:7493 Channel sofia/622131180035-external/0817145779 entering state [ready][200]
2024-02-16 12:34:23.521365 99.43% [NOTICE] sofia.c:8622 Channel [sofia/622131180035-external/0817145779] has been answered
2024-02-16 12:34:23.521365 99.43% [DEBUG] switch_channel.c:3912 (sofia/622131180035-external/0817145779) Callstate Change EARLY -> ACTIVE
send 1082 bytes to udp/[182.253.56.161]:5590 at 12:34:23.527427:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2024-02-16 12:34:23.521365 99.43% [NOTICE] switch_ivr.c:820 Channel [sofia/internal/101@pbx.example.co.id] has been answered
2024-02-16 12:34:23.521365 99.43% [DEBUG] switch_channel.c:3912 (sofia/internal/101@pbx.example.co.id) Callstate Change EARLY -> ACTIVE
2024-02-16 12:34:23.521365 99.43% [DEBUG] sofia.c:7493 Channel sofia/internal/101@pbx.example.co.id entering state [completed][200]
send 1082 bytes to udp/[182.253.56.161]:5590 at 12:34:24.027942:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

send 1082 bytes to udp/[182.253.56.161]:5590 at 12:34:25.028110:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

send 1082 bytes to udp/[182.253.56.161]:5590 at 12:34:27.029121:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

send 1082 bytes to udp/[182.253.56.161]:5590 at 12:34:31.029173:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

send 1082 bytes to udp/[182.253.56.161]:5590 at 12:34:35.029211:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

send 1082 bytes to udp/[182.253.56.161]:5590 at 12:34:39.029241:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

send 1082 bytes to udp/[182.253.56.161]:5590 at 12:34:43.029277:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

send 1082 bytes to udp/[182.253.56.161]:5590 at 12:34:47.029315:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

send 1082 bytes to udp/[182.253.56.161]:5590 at 12:34:51.029365:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

send 1082 bytes to udp/[182.253.56.161]:5590 at 12:34:55.030395:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 182.253.56.161:5590;branch=z9hG4bKPjd8a655bd6d1a4089bb7a1ea4e62276ce;rport=5590
From: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
To: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 3362 INVITE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 191
Remote-Party-ID: "0817145779" <sip:0817145779@pbx.example.co.id>;party=calling;privacy=off;screen=no

v=0
o=GANG 744233618 744233619 IN IP4 43.245.185.3
s=-
c=IN IP4 43.245.185.3
t=0 0
m=audio 10516 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

send 611 bytes to udp/[182.253.56.161]:5590 at 12:34:55.527482:
------------------------------------------------------------------------
BYE sip:101@182.253.56.161:5590;ob SIP/2.0
Via: SIP/2.0/UDP 172.31.203.210;rport;branch=z9hG4bKpvSm30UDjyyer
Max-Forwards: 70
From: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
To: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
CSeq: 79475255 BYE
Contact: <sip:0817145779@172.31.203.210:5060;transport=udp>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Reason: SIP;cause=408;text="ACK Timeout"
Content-Length: 0


2024-02-16 12:34:55.521361 99.63% [DEBUG] sofia.c:7493 Channel sofia/internal/101@pbx.example.co.id entering state [terminating][0]
2024-02-16 12:34:55.521361 99.63% [NOTICE] sofia.c:8735 Hangup sofia/internal/101@pbx.example.co.id [CS_HIBERNATE] [MANDATORY_IE_MISSING]
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_ivr_bridge.c:1334 sofia/internal/101@pbx.example.co.id skip receive message [UNBRIDGE] (channel is hungup already)
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.co.id) Running State Change CS_HANGUP (Cur 2 Tot 6)
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/101@pbx.example.co.id) Callstate Change ACTIVE -> HANGUP
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/101@pbx.example.co.id) State HANGUP
2024-02-16 12:34:55.521361 99.63% [DEBUG] mod_sofia.c:469 Channel sofia/internal/101@pbx.example.co.id hanging up, cause: MANDATORY_IE_MISSING
2024-02-16 12:34:55.521361 99.63% [NOTICE] switch_ivr_bridge.c:1473 Hangup sofia/622131180035-external/0817145779 [CS_HIBERNATE] [MANDATORY_IE_MISSING]
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:59 sofia/internal/101@pbx.example.co.id Standard HANGUP, cause: MANDATORY_IE_MISSING
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/101@pbx.example.co.id) State HANGUP going to sleep
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_ivr_bridge.c:1334 sofia/622131180035-external/0817145779 skip receive message [UNBRIDGE] (channel is hungup already)
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/101@pbx.example.co.id) State Change CS_HANGUP -> CS_REPORTING
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:581 (sofia/622131180035-external/0817145779) Running State Change CS_HANGUP (Cur 2 Tot 6)
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/101@pbx.example.co.id) Running State Change CS_REPORTING (Cur 2 Tot 6)
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:844 (sofia/622131180035-external/0817145779) Callstate Change ACTIVE -> HANGUP
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:846 (sofia/622131180035-external/0817145779) State HANGUP
2024-02-16 12:34:55.521361 99.63% [DEBUG] mod_sofia.c:469 Channel sofia/622131180035-external/0817145779 hanging up, cause: MANDATORY_IE_MISSING
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/101@pbx.example.co.id) State REPORTING
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:168 sofia/internal/101@pbx.example.co.id Standard REPORTING, cause: MANDATORY_IE_MISSING
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/101@pbx.example.co.id) State REPORTING going to sleep
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/101@pbx.example.co.id) State Change CS_REPORTING -> CS_DESTROY
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_session.c:1744 Session 5 (sofia/internal/101@pbx.example.co.id) Locked, Waiting on external entities
2024-02-16 12:34:55.521361 99.63% [NOTICE] switch_core_session.c:1762 Session 5 (sofia/internal/101@pbx.example.co.id) Ended
2024-02-16 12:34:55.521361 99.63% [NOTICE] switch_core_session.c:1766 Close Channel sofia/internal/101@pbx.example.co.id [CS_DESTROY]
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/101@pbx.example.co.id) Running State Change CS_DESTROY (Cur 1 Tot 6)
2024-02-16 12:34:55.521361 99.63% [DEBUG] mod_sofia.c:523 Sending BYE to sofia/622131180035-external/0817145779
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:59 sofia/622131180035-external/0817145779 Standard HANGUP, cause: MANDATORY_IE_MISSING
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:846 (sofia/622131180035-external/0817145779) State HANGUP going to sleep
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:616 (sofia/622131180035-external/0817145779) State Change CS_HANGUP -> CS_REPORTING
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:581 (sofia/622131180035-external/0817145779) Running State Change CS_REPORTING (Cur 1 Tot 6)
send 573 bytes to udp/[43.245.185.3]:5060 at 12:34:55.529882:
------------------------------------------------------------------------
BYE sip:43.245.185.3:5060 SIP/2.0
Via: SIP/2.0/UDP 43.245.185.3:5080;rport;branch=z9hG4bKXc00pNB0aa2je
Max-Forwards: 70
From: "101" <sip:622131180035@43.245.185.3:5060>;tag=QgyKSZ78DKZXg
To: <sip:0817145779@43.245.185.3:5060>;tag=6aa2e674-a61a-4e4f-9630-a2ce62ebb063
Call-ID: 7b9795ff-4727-123d-16bf-00163e038571
CSeq: 79475236 BYE
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: path, replaces
Reason: Q.850;cause=96;text="MANDATORY_IE_MISSING"
Content-Length: 0


2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:932 (sofia/622131180035-external/0817145779) State REPORTING
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:168 sofia/622131180035-external/0817145779 Standard REPORTING, cause: MANDATORY_IE_MISSING
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:932 (sofia/622131180035-external/0817145779) State REPORTING going to sleep
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/101@pbx.example.co.id) State DESTROY
2024-02-16 12:34:55.521361 99.63% [DEBUG] mod_sofia.c:380 sofia/internal/101@pbx.example.co.id SOFIA DESTROY
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:175 sofia/internal/101@pbx.example.co.id Standard DESTROY
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/101@pbx.example.co.id) State DESTROY going to sleep
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:607 (sofia/622131180035-external/0817145779) State Change CS_REPORTING -> CS_DESTROY
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_session.c:1744 Session 6 (sofia/622131180035-external/0817145779) Locked, Waiting on external entities
2024-02-16 12:34:55.521361 99.63% [NOTICE] switch_core_session.c:1762 Session 6 (sofia/622131180035-external/0817145779) Ended
2024-02-16 12:34:55.521361 99.63% [NOTICE] switch_core_session.c:1766 Close Channel sofia/622131180035-external/0817145779 [CS_DESTROY]
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:735 (sofia/622131180035-external/0817145779) Running State Change CS_DESTROY (Cur 0 Tot 6)
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:745 (sofia/622131180035-external/0817145779) State DESTROY
2024-02-16 12:34:55.521361 99.63% [DEBUG] mod_sofia.c:380 sofia/622131180035-external/0817145779 SOFIA DESTROY
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:175 sofia/622131180035-external/0817145779 Standard DESTROY
2024-02-16 12:34:55.521361 99.63% [DEBUG] switch_core_state_machine.c:745 (sofia/622131180035-external/0817145779) State DESTROY going to sleep
recv 354 bytes from udp/[43.245.185.3]:5060 at 12:34:55.531949:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 43.245.185.3:5080;rport=5080;received=149.129.248.234;branch=z9hG4bKXc00pNB0aa2je
Call-ID: 7b9795ff-4727-123d-16bf-00163e038571
From: "101" <sip:622131180035@43.245.185.3:5060>;tag=QgyKSZ78DKZXg
To: <sip:0817145779@43.245.185.3:5060>;tag=6aa2e674-a61a-4e4f-9630-a2ce62ebb063
CSeq: 79475236 BYE
Content-Length: 0


recv 331 bytes from udp/[182.253.56.161]:5590 at 12:34:55.535381:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/UDP 172.31.203.210;branch=z9hG4bKpvSm30UDjyyer;received=149.129.248.234;rport=5060
Call-ID: 2edb4ebbfe2240beb5399213a39b5652
From: <sip:0817145779@pbx.example.co.id>;tag=N5Umg2Qm9ZNZN
To: <sip:101@pbx.example.co.id>;tag=05b814b5d4104cd5a6cf7860dc29fb08
CSeq: 79475255 BYE
Content-Length: 0


freeswitch@pbx> /exit
 
Last edited:

Win

Member
Feb 12, 2024
49
2
8
freeswitch@pbx> nat_map status

false
2024-02-16 20:31:04.485296 99.47% [ERR] mod_commands.c:757 nat_map API called while NAT not initialized

this might also causing it!
 

Win

Member
Feb 12, 2024
49
2
8
Hi @voipBull,

after 3 days struggeled :(, finally I resolved it yesterday (that was a good saturday night haha)

it's actually pretty simple!..

our net is: FS eth0 172.1.2.3 --> NAT --> 149.1.2.3 --> Internet Extensions

set the following in /vars

external_rtp_ip to 149.1.2.3
external_sip_ip to 149.1.2.3

and set:

ext-rtp-ip to $${external_rtp_ip}
ext-sip_ip to $${external_sip_ip}

restart the box

I just want to share here, because I don't want someone being struggled like me :(
 
  • Like
Reactions: cagriaksu
Status
Not open for further replies.