freeswitch
freeswitch copied to clipboard
Published
20 hours ago •
signalwire
signalwire
"sofia recover" can't work correctly
trafficstars
Describe the bug The environment is like "https://freeswitch.org/confluence/display/FREESWITCH/HA+keepalived" , "sofia recover" cann't recover the calls in progress.I obtained the sip signaling and found that the cseq of the re-invite signaling sent by "sofia recover" is smaller than that of the invite signaling. This leads to "SIP/2.0 500 Invalid CSeq" To Reproduce FreeSwitchA and FreeSwitchB use the same DB, FreeSwitchA is master,FreeSwitchB is backup; 1: FreeSwitchA
originate user/79739980 9196
fsctl crash
2: FreeSwitchB
sofia recover
Expected behavior calls can be recoverd.
Package version or git hash
- Version [1.10.8]
Trace logs
2022-10-19 07:34:13.561124 99.07% [NOTICE] switch_channel.c:1123 New Channel sofia/internal/[email protected]:56580 [42a396e6-4d2a-4b62-bde3-a75df666d926]
2022-10-19 07:34:13.561124 99.07% [NOTICE] switch_channel.c:1121 Rename Channel sofia/internal/[email protected]:56580->sofia/internal/[email protected]:56580 [42a39a-4b62-bde3-a75df666d926]
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_media.c:3883 Set Codec sofia/internal/[email protected]:56580 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_codec.c:111 sofia/internal/[email protected]:56580 Original read codec set to PCMU:0
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_media.c:8787 AUDIO RTP [sofia/internal/[email protected]:56580] 172.16.154.71 port 19632 -> 172.16.154.33 port 4000 0 ms: 20
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_rtp.c:4619 Starting timer [soft] 160 bytes per 20ms
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_media.c:9099 sofia/internal/[email protected]:56580 Set 2833 dtmf send payload to 101
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_media.c:9106 sofia/internal/[email protected]:56580 Set 2833 dtmf receive payload to 101
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_media.c:9129 sofia/internal/[email protected]:56580 Set rtp dtmf delay to 40
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_sqldb.c:3243 (sofia/internal/[email protected]:56580) State Change CS_NEW -> CS_INIT
2022-10-19 07:34:13.561124 99.07% [NOTICE] switch_core_sqldb.c:3244 Resurrecting fallen channel sofia/internal/[email protected]:56580
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/[email protected]:56580) Running State Change CS_INIT (Cur 1 Tot 1)
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/[email protected]:56580) State INIT
2022-10-19 07:34:13.561124 99.07% [DEBUG] mod_sofia.c:97 sofia/internal/[email protected]:56580 SOFIA INIT
2022-10-19 07:34:13.561124 99.07% [INFO] sofia_glue.c:1654 sofia/internal/[email protected]:56580 sending invite call-id: 6a3411a6-ca23-123b-a596-a4bb6dd98a98
2022-10-19 07:34:13.561124 99.07% [DEBUG] sofia_glue.c:1657 sofia/internal/[email protected]:56580 sending invite version: 1.10.8 -release-20-3510866140 64bit
Local SDP:
v=0
o=FreeSWITCH 1666145221 1666145223 IN IP4 172.16.154.71
s=FreeSWITCH
c=IN IP4 172.16.154.71
t=0 0
m=audio 19632 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/0
a=fmtp:101 0-15
a=ptime:20
a=sendrecv
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_state_machine.c:40 sofia/internal/[email protected]:56580 Standard INIT
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_state_machine.c:46 (sofia/internal/[email protected]:56580) State Change CS_INIT -> CS_EXECUTE
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/[email protected]:56580) State INIT going to sleep
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/[email protected]:56580) Running State Change CS_EXECUTE (Cur 1 Tot 1)
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/[email protected]:56580) State EXECUTE
2022-10-19 07:34:13.561124 99.07% [DEBUG] mod_sofia.c:213 sofia/internal/[email protected]:56580 SOFIA EXECUTE
2022-10-19 07:34:13.561124 99.07% [DEBUG] switch_core_state_machine.c:323 sofia/internal/[email protected]:56580 Standard EXECUTE
EXECUTE [depth=0] sofia/internal/[email protected]:56580 answer()
EXECUTE [depth=0] sofia/internal/[email protected]:56580 echo()
2022-10-19 07:34:13.561124 99.07% [DEBUG] sofia.c:7502 Channel sofia/internal/[email protected]:56580 entering state [calling][0]
2022-10-19 07:34:13.581195 99.07% [DEBUG] sofia.c:7502 Channel sofia/internal/[email protected]:56580 entering state [terminated][500]
2022-10-19 07:34:13.581195 99.07% [NOTICE] sofia.c:8745 Hangup sofia/internal/[email protected]:56580 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]
2022-10-19 07:34:13.581195 99.07% [DEBUG] switch_core_state_machine.c:337 sofia/internal/[email protected]:56580 skip receive message [VIDEO_SYNC] (channel is hungup alre
2022-10-19 07:34:13.581195 99.07% [DEBUG] switch_core_state_machine.c:338 sofia/internal/[email protected]:56580 skip receive message [REQUEST_IMAGE_MEDIA] (channel is huready)
2022-10-19 07:34:13.581195 99.07% [DEBUG] switch_core_session.c:2977 sofia/internal/[email protected]:56580 skip receive message [PHONE_EVENT] (channel is hungup already)
2022-10-19 07:34:13.581195 99.07% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/[email protected]:56580) State EXECUTE going to sleep
2022-10-19 07:34:13.581195 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/[email protected]:56580) Running State Change CS_HANGUP (Cur 1 Tot 1)
2022-10-19 07:34:13.581195 99.07% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/[email protected]:56580) Callstate Change DOWN -> HANGUP
2022-10-19 07:34:13.581195 99.07% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/[email protected]:56580) State HANGUP
2022-10-19 07:34:13.581195 99.07% [DEBUG] mod_sofia.c:468 Channel sofia/internal/[email protected]:56580 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:59 sofia/internal/[email protected]:56580 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/[email protected]:56580) State HANGUP going to sleep
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/[email protected]:56580) State Change CS_HANGUP -> CS_REPORTING
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/[email protected]:56580) Running State Change CS_REPORTING (Cur 1 Tot 1)
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/[email protected]:56580) State REPORTING
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:168 sofia/internal/[email protected]:56580 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/[email protected]:56580) State REPORTING going to sleep
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/[email protected]:56580) State Change CS_REPORTING -> CS_DESTROY
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_session.c:1747 Session 1 (sofia/internal/[email protected]:56580) Locked, Waiting on external entities
2022-10-19 07:34:13.600347 99.07% [NOTICE] switch_core_session.c:1765 Session 1 (sofia/internal/[email protected]:56580) Ended
2022-10-19 07:34:13.600347 99.07% [NOTICE] switch_core_session.c:1769 Close Channel sofia/internal/[email protected]:56580 [CS_DESTROY]
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/[email protected]:56580) Running State Change CS_DESTROY (Cur 0 Tot 1)
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/[email protected]:56580) State DESTROY
2022-10-19 07:34:13.600347 99.07% [DEBUG] mod_sofia.c:379 sofia/internal/[email protected]:56580 SOFIA DESTROY
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:175 sofia/internal/[email protected]:56580 Standard DESTROY
2022-10-19 07:34:13.600347 99.07% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/[email protected]:56580) State DESTROY going to sleep
You said you patched sofia_glue.c, could you do a PR for us to review and make sure your approach covers all the edge cases?
You said you patched sofia_glue.c, could you do a PR for us to review and make sure your approach covers all the edge cases?
Is there any update on this issue? I am running freeswitch with keepalived and the same db. when I run sofia recover I see simillar problems with this issue so recover doesn't work properly.
