I met a strange question in FreeSWITCH. FreeSWITCH version: 1.10.7, OS: CentOS 7.9
Registered two users A and B, A is hotspot or wifi, B is 4G, B make call A, it is successful, voice and video is ok between A and B, But I call user B by FreeSWITCH command, It's not reachable, or once in a while is ok!
Command:
bgapi originate user/B &echo
call log:
freeswitch@ecs-44d8-0514058> bgapi originate user/1000000701100012 &echo
+OK Job-UUID: 293cf906-86c5-11ed-9d16-3b47fece8f98
2022-12-28 23:34:47.676493 99.70% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_ivr_originate.c:2281 Parsing global variables
2022-12-28 23:34:47.696498 99.70% [NOTICE] switch_channel.c:1123 New Channel sofia/internal/1000000701100012@192.168.43.174:56858 [293ec5d8-86c5-11ed-9d1a-3b47fece8f98]
2022-12-28 23:34:47.696498 99.70% [DEBUG] mod_sofia.c:5121 (sofia/internal/1000000701100012@192.168.43.174:56858) State Change CS_NEW -> CS_INIT
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1000000701100012@192.168.43.174:56858) Running State Change CS_INIT (Cur 1 Tot 844)
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1000000701100012@192.168.43.174:56858) State INIT
2022-12-28 23:34:47.696498 99.70% [DEBUG] mod_sofia.c:97 sofia/internal/1000000701100012@192.168.43.174:56858 SOFIA INIT
2022-12-28 23:34:47.696498 99.70% [DEBUG] sofia_glue.c:1620 sip:1000000701100012@123.116.254.94:4392;transport=udp Setting proxy route to sofia/internal/1000000701100012@192.168.43.174:56858
2022-12-28 23:34:47.696498 99.70% [INFO] sofia_glue.c:1651 sofia/internal/1000000701100012@192.168.43.174:56858 sending invite call-id: (null)
2022-12-28 23:34:47.696498 99.70% [DEBUG] sofia_glue.c:1654 sofia/internal/1000000701100012@192.168.43.174:56858 sending invite version: 1.10.7 -release 64bit
Local SDP:
v=0
o=FreeSWITCH 1672214247 1672214248 IN IP4 125.124.216.102
s=FreeSWITCH
c=IN IP4 125.124.216.102
t=0 0
m=audio 27440 RTP/AVP 102 0 8
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=ptime:20
a=sendrecv
m=video 25820 RTP/AVP 103
b=AS:4096
a=rtpmap:103 H264/90000
a=rtpmap:104 VP8/90000
a=sendrecv
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000000701100012@192.168.43.174:56858 Standard INIT
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000000701100012@192.168.43.174:56858) State Change CS_INIT -> CS_ROUTING
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/1000000701100012@192.168.43.174:56858) State INIT going to sleep
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1000000701100012@192.168.43.174:56858) Running State Change CS_ROUTING (Cur 1 Tot 844)
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1000000701100012@192.168.43.174:56858) State ROUTING
2022-12-28 23:34:47.696498 99.70% [DEBUG] mod_sofia.c:158 sofia/internal/1000000701100012@192.168.43.174:56858 SOFIA ROUTING
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000000701100012@192.168.43.174:56858) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/1000000701100012@192.168.43.174:56858) State ROUTING going to sleep
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1000000701100012@192.168.43.174:56858) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 844)
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_core_state_machine.c:659 (sofia/internal/1000000701100012@192.168.43.174:56858) State CONSUME_MEDIA
2022-12-28 23:34:47.696498 99.70% [DEBUG] switch_core_state_machine.c:659 (sofia/internal/1000000701100012@192.168.43.174:56858) State CONSUME_MEDIA going to sleep
2022-12-28 23:34:47.696498 99.70% [DEBUG] sofia.c:7499 Channel sofia/internal/1000000701100012@192.168.43.174:56858 entering state [calling][0]
2022-12-28 23:34:51.876495 99.70% [NOTICE] switch_cpp.cpp:1465 lua take the users...
2022-12-28 23:34:51.876495 99.70% [NOTICE] switch_cpp.cpp:1465 start connect DB...
2022-12-28 23:34:51.876495 99.70% [NOTICE] switch_cpp.cpp:1465 123456
2022-12-28 23:35:16.876494 99.63% [DEBUG] sofia.c:6575 Ping to sip user '1000000701100012@125.124.216.102' succeeded with code 200 - count 1, state Reachable
2022-12-28 23:35:19.696492 99.67% [DEBUG] sofia.c:7499 Channel sofia/internal/1000000701100012@192.168.43.174:56858 entering state [terminated][408]
2022-12-28 23:35:19.696492 99.67% [NOTICE] sofia.c:8738 Hangup sofia/internal/1000000701100012@192.168.43.174:56858 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1000000701100012@192.168.43.174:56858) Running State Change CS_HANGUP (Cur 1 Tot 844)
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/1000000701100012@192.168.43.174:56858) Callstate Change DOWN -> HANGUP
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/1000000701100012@192.168.43.174:56858) State HANGUP
2022-12-28 23:35:19.696492 99.67% [DEBUG] mod_sofia.c:468 Channel sofia/internal/1000000701100012@192.168.43.174:56858 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:59 sofia/internal/1000000701100012@192.168.43.174:56858 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/1000000701100012@192.168.43.174:56858) State HANGUP going to sleep
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/1000000701100012@192.168.43.174:56858) State Change CS_HANGUP -> CS_REPORTING
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/1000000701100012@192.168.43.174:56858) Running State Change CS_REPORTING (Cur 1 Tot 844)
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/1000000701100012@192.168.43.174:56858) State REPORTING
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:168 sofia/internal/1000000701100012@192.168.43.174:56858 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/1000000701100012@192.168.43.174:56858) State REPORTING going to sleep
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/1000000701100012@192.168.43.174:56858) State Change CS_REPORTING -> CS_DESTROY
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_session.c:1753 Session 844 (sofia/internal/1000000701100012@192.168.43.174:56858) Locked, Waiting on external entities
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2022-12-28 23:35:19.696492 99.67% [NOTICE] switch_ivr_originate.c:3039 Cannot create outgoing channel of type [user] cause: [RECOVERY_ON_TIMER_EXPIRE]
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_ivr_originate.c:4035 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2022-12-28 23:35:19.696492 99.67% [NOTICE] switch_core_session.c:1771 Session 844 (sofia/internal/1000000701100012@192.168.43.174:56858) Ended
2022-12-28 23:35:19.696492 99.67% [NOTICE] switch_core_session.c:1775 Close Channel sofia/internal/1000000701100012@192.168.43.174:56858 [CS_DESTROY]
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/1000000701100012@192.168.43.174:56858) Running State Change CS_DESTROY (Cur 0 Tot 844)
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/1000000701100012@192.168.43.174:56858) State DESTROY
2022-12-28 23:35:19.696492 99.67% [DEBUG] mod_sofia.c:379 sofia/internal/1000000701100012@192.168.43.174:56858 SOFIA DESTROY
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:175 sofia/internal/1000000701100012@192.168.43.174:56858 Standard DESTROY
2022-12-28 23:35:19.696492 99.67% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/1000000701100012@192.168.43.174:56858) State DESTROY going to sleep
NAT config:
#internal.xml
<param name="apply-nat-acl" value="rfc1918.auto"/> // or nat.auto
user B(wifi or hotspot network) show registrations info:
reg_user,realm,token,url,expires,network_ip,network_port,network_proto,hostname,metadata
1000000701100012,125.124.216.102,463403000446,sofia/internal/sip:1000000701100012@192.168.43.174:56858;transport=udp;fs_nat=yes;fs_path=sip%3A1000000701100012%40123.116.254.94%3A4392%3Btransport%3Dudp,1672241946,123.116.254.94,4392,udp,ecs-44d8-0514058,
freeswitch@ecs-44d8-0514058> sofia status profile internal
Name internal
Domain Name N/A
Auto-NAT true
DBName sofia_reg_internal
Pres Hosts 125.124.216.102,172.16.0.101
Dialplan XML
Context default
Challenge Realm auto_from
RTP-IP 172.16.0.101
Ext-RTP-IP 125.124.216.102
SIP-IP 172.16.0.101
Ext-SIP-IP 125.124.216.102
By wireshark , FreeSWITCH send more INVITE, but user not recv any one. But is B make call A , It can be connected immediately. enter image description here
I guess is NAT problem， But I cannot Analysis and verification
By Comparative test， Why B call A is ok. but freeSWITCH call B by command. It is not reachable.
I config internal.xml
// modify value to nat.auto, it is not usefulI've been debugging for several days. I really don't know where the problem is？Who can help me， thanks for everyone!
thanks all！
after several days of testing. I find the size of packet of FreeSWITCH Sent out beyond MTU. Actual INVITE package is 1474Bype, add UDP head size(8Byte), IP Head(20Byte) and so on, at last the total size of package beyond MTU，
So Terminal APP maybe can not recv This INVITE. When I reduce size of INVITE Message, terminal app can receive INVITE message immediately。
it works very good！ thanks all!
