search

freeswitch / spandsp

SpanDSP is a low-level signal processing library that modulates and demodulates signals commonly used in telephony, such as the "noise" generated by a fax modem or DTMF touchpad.
Other
141 stars 117 forks source link

FreeSWITCH Crash (most likely in spandsp's t30.c) #38

Closed pragmatrix closed 2 years ago

pragmatrix commented 2 years ago

Hi, one of our FreeSWITCH machines recently deadlocked or livelocked. No connections to the Event Socket port 8021 were accepted anymore and after a superficial analysis we are suspecting a bug in spandsp because the last line in the log indicates that a fax ECM frame was received of 3 bytes in length, which in turn caused a call to a memcpy with len == -1.

Here are the last few log entries:

2022-01-17 16:42:06.698682 [DEBUG] mod_spandsp_fax.c:295 FLOW FAX Set rx type 7
2022-01-17 16:42:06.698682 [DEBUG] mod_spandsp_fax.c:295 FLOW FAX Set tx type 0
2022-01-17 16:42:06.698682 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 Start T2
2022-01-17 16:42:06.718682 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Carrier down (-1) in state F_DOC_ECM
2022-01-17 16:42:06.718682 [WARNING] mod_spandsp_fax.c:295 WARNING T.30 ECM carrier not found
2022-01-17 16:42:06.718682 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 Status changing to Carrier lost during fax receive
2022-01-17 16:42:07.478681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_DOC_ECM
2022-01-17 16:42:07.478681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_DOC_ECM
2022-01-17 16:42:07.618681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Training failed (-5) in state F_DOC_ECM
2022-01-17 16:42:07.678681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Carrier down (-1) in state F_DOC_ECM
2022-01-17 16:42:07.678681 [WARNING] mod_spandsp_fax.c:295 WARNING T.30 ECM carrier not found
2022-01-17 16:42:07.678681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_DOC_ECM
2022-01-17 16:42:07.678681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Carrier down (-1) in state F_DOC_ECM
2022-01-17 16:42:07.678681 [WARNING] mod_spandsp_fax.c:295 WARNING T.30 ECM carrier not found
2022-01-17 16:42:07.678681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Carrier up (-2) in state F_DOC_ECM
2022-01-17 16:42:07.818681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Training in progress (-3) in state F_DOC_ECM
2022-01-17 16:42:07.838681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Training succeeded (-4) in state F_DOC_ECM
2022-01-17 16:42:07.838681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Abort (-8) in state F_DOC_ECM
2022-01-17 16:42:07.838681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Framing OK (-6) in state F_DOC_ECM
2022-01-17 16:42:07.838681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 Start T1A
2022-01-17 16:42:07.858681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 Bad HDLC CRC received
2022-01-17 16:42:07.858681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 Bad HDLC CRC received
2022-01-17 16:42:07.878681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 Bad HDLC CRC received
2022-01-17 16:42:07.878681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Abort (-8) in state F_DOC_ECM
2022-01-17 16:42:07.898681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Abort (-8) in state F_DOC_ECM
2022-01-17 16:42:07.978681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 Bad HDLC CRC received
2022-01-17 16:42:07.978681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 HDLC signal status is Abort (-8) in state F_DOC_ECM
2022-01-17 16:42:08.038681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 Stop T1A (278400 remaining)
2022-01-17 16:42:08.038681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 Rx:  FCD without final frame tag
2022-01-17 16:42:08.038681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 Rx:  ff 03 06
2022-01-17 16:42:08.038681 [DEBUG] mod_spandsp_fax.c:295 FLOW T.30 Storing ECM frame 97, length -1

The code in t30.c I suspect caused the problem:

https://github.com/freeswitch/spandsp/blob/284fe91dd068d0cf391139110fdc2811043972b9/src/t30.c#L3589-L3590

And the full spandsp related log:

spandsp-error.log

FreeSWITCH version was most likely version 1.10.6.. We are not 100% sure, because we have updated it to 1.10.7 right before reinstating the server again.

mjerris commented 2 years ago

please provide a backtrace of all threads and reopen this issue once it’s attached. this kind of issue can’t be reviewed without that info

pragmatrix commented 2 years ago

We don't have that backtrace now. We have to wait for another crash.

this kind of issue can’t be reviewed without that info

I disagree. The code path is fairly obvious from the log, and the memcpy above can't handle a Rx of size 3 and will most likely lead to UB. Building a test case should be fairly simple for someone accustomed with the code. I'll try my best as soon I've time for that.