karlheyes / icecast-kh

KH branch of icecast
GNU General Public License v2.0
297 stars 105 forks source link

segfault on version KH 15 #364

Closed luca066 closed 1 year ago

luca066 commented 2 years ago

Hi, I'm using Icecast KH 15 on a Centos 7 server. We have many servers with the same configuration, but one server has Icecast process crashing about every 24 hours. On Centos messages log file, then Icecast crashes I see: Mar 19 11:19:44 server12 kernel: icecast[1607]: segfault at 1398 ip 00000000004159a2 sp 00007fd310282c30 error 4 in icecast[400000+55000] but not always, sometimes Icecast crashes and I don't see any message on Centos log file.

I tried to use version KH 13, but the issue continues to appear. I tried to change the server, but even on the new machine the issue appears.

I raised the log level to debug and this is the log file (Icecast crashed at 08:57:55 and it's restarted automatically by a script at 08:58:01).

[2022-03-20  08:57:55] DBUG client/worker 0x1734730 now has 0 clients
[2022-03-20  08:57:55] DBUG stats/modify_node_event update "/radio12.mp3" outgoing_kbitrate (168)
[2022-03-20  08:57:55] DBUG stats/modify_node_event update "/radio12.mp3" incoming_bitrate (97880)
[2022-03-20  08:57:55] DBUG stats/modify_node_event update "/radio12.mp3" total_bytes_read (317332080)
[2022-03-20  08:57:55] DBUG stats/modify_node_event update "/radio12.mp3" total_bytes_sent (271187426)
[2022-03-20  08:57:55] DBUG stats/modify_node_event update "/radio12.mp3" total_mbytes_sent (258)
[2022-03-20  08:57:55] DBUG stats/modify_node_event update "/radio12.mp3" queue_size (119232)
[2022-03-20  08:57:55] DBUG stats/modify_node_event update "/radio12.mp3" connected (26445)
[2022-03-20  08:57:55] DBUG client/worker_add_pending_clients Added 1 pending clients to 0x1734730
[2022-03-20  08:57:55] DBUG client/worker 0x1734730 now has 1 clients
[2022-03-20  08:57:55] DBUG connection/_handle_get_request start with /onair.xsl
[2022-03-20  08:57:55] DBUG auth/add_authenticated_listener Stats request, sending XSL transformed stats
[2022-03-20  08:57:55] DBUG client/client_destroy keepalive detected on 116.202.98.215, placing back onto worker
[2022-03-20  08:57:55] DBUG client/worker 0x1734730 now has 0 clients
[2022-03-20  08:57:55] DBUG client/worker_add_pending_clients Added 1 pending clients to 0x1734730
[2022-03-20  08:57:55] DBUG client/worker 0x1734730 now has 1 clients
[2022-03-20  08:57:55] DBUG client/worker 0x1734730 now has 0 clients
[2022-03-20  08:58:01] INFO thread/ lock abort set to 0
[2022-03-20  08:58:01] INFO logging/recheck_log_file Using log file /var/log/icecast/access.log
[2022-03-20  08:58:01] INFO main/server_proc_init Icecast 2.4.0-kh15 server reading configuration from /opt/icecast/latest/etc/icecast.xml
[2022-03-20  08:58:01] INFO connection/get_ssl_certificate SSL certificate found at /opt/icecast/latest/etc/ice.pem
[2022-03-20  08:58:01] INFO connection/get_ssl_certificate SSL using ciphers ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-DSS-AES128-GCM-SHA256:kEDH+AESGCM:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA256:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA384:ECDHE-RSA-AES256-SHA:ECDHE-ECDSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES128-SHA:DHE-DSS-AES128-SHA256:DHE-RSA-AES256-SHA256:DHE-DSS-AES256-SHA:DHE-RSA-AES256-SHA:ECDHE-RSA-DES-CBC3-SHA:ECDHE-ECDSA-DES-CBC3-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:AES:DES-CBC3-SHA:HIGH:!aNULL:!eNULL:!EXPORT:!DES:!RC4:!MD5:!PSK:!aECDH:!EDH-DSS-DES-CBC3-SHA:!EDH-RSA-DES-CBC3-SHA:!KRB5-DES-CBC3-SHA
[2022-03-20  08:58:01] INFO connection/connection_setup_sockets 2 listener socket(s) for port 443
[2022-03-20  08:58:01] INFO connection/connection_setup_sockets 2 listener socket(s) for port 80
[2022-03-20  08:58:01] INFO connection/connection_setup_sockets 4 listening sockets setup complete

I'm not able to detect what is going wrong, which is the reason of the crash. CPU is always under 10%, memory is always free, I don't think that it could be related to hardware resources.

Now I'm trying version KH 10, I want to see if there could be a Icecast version that not suffer of this "unknown" issue. Anyone may have an idea about how can I understand what is going wrong? Kind regards, Luka

TheRealMattLear commented 1 year ago

@luca066 did you manage to solve the problem? We're seeing almost the exact same error now:

Sep 19 14:34:00 host481527 kernel: icecast[29764]: segfault at 3161 ip 00000000004159a2 sp 00007f7ec37b6c30 error 4 in icecast[400000+55000]
luca066 commented 1 year ago

I don’t know the reason of the crash, we have many servers using KH 15 and only one has the issue that we solved using KH 10 version. Try to use KH 10 to check if it will crash again.

On 20 Oct 2022, at 09:15, Matthew Lear @.***> wrote:

@luca066 https://github.com/luca066 did you manage to solve the problem? We're seeing almost the exact same error now:

Sep 19 14:34:00 host481527 kernel: icecast[29764]: segfault at 3161 ip 00000000004159a2 sp 00007f7ec37b6c30 error 4 in icecast[400000+55000] — Reply to this email directly, view it on GitHub https://github.com/karlheyes/icecast-kh/issues/364#issuecomment-1285054875, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAZO3GAOQCJJGC56UTO6BNDWEDWPVANCNFSM5RJIJJFQ. You are receiving this because you were mentioned.

boteman commented 1 year ago

My very general guess is that it could be a non-obvious typographic error in the config file, something silly like a missing semi-colon or an embedded control character. That would explain why only one of your servers experience the problem. I have occasionally seen this kind of thing with some other software projects that did not fully parse things for errors. At least it's an idea to check. I have never had a segfault from icecast. HTH

luca066 commented 1 year ago

It’s a strange case, same config file used with KH15 version and I have segfault after few hours, with version KH10 the server is running without any issue (same config file). I even tried to reinstall the server, os and Icecast ... no way.

On 20 Oct 2022, at 23:09, boteman @.***> wrote:

My very general guess is that it could be a non-obvious typographic error in the config file, something silly like a missing semi-colon or an embedded control character. That would explain why only one of your servers experience the problem. I have occasionally seen this kind of thing with some other software projects that did not fully parse things for errors. At least it's an idea to check. I have never had a segfault from icecast. HTH

— Reply to this email directly, view it on GitHub https://github.com/karlheyes/icecast-kh/issues/364#issuecomment-1286154341, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAZO3GAUBZXV2NW5H4OYTZTWEGYHNANCNFSM5RJIJJFQ. You are receiving this because you were mentioned.

karlheyes commented 1 year ago

The kh16.1 update has all known fixes in at the moment. Without the specifics on what is actually in use at the time it's hard to say whether anything in particular is resolved. I've done a bunch of locking changes recently so hard to say whether that may resolve it (hardware quirks can exhibit in some situations more easily). If you want to try kh16.1 or rebuild kh15 with debug (make debug) and then I can look into it. Grabbing a core file from the crash may be helpful in such cases.

luca066 commented 1 year ago

Hi Karl,

last night I installed version 2.4.0-kh16 , but after few hours the server crashed, like version kh15 (now I re-activated version kh10 that works without any crash - it was running since March without any restart). What can I do to help you to detect this issue? I’m not an expert, I can build kh15 using "make debug” and then? Icecast will create an extra debug file?

About the core dump, I’ll enable the server to creates core files and I’ll restart kh16 during the weekend.

Another question about kh16: using the new kh16, some mp3 streams had issues playing with cracks/jumps. On the log files there was many messages like these:

[2022-12-15 15:04:23] WARN format-mp3/validate_mpeg source /studio04.mp3, len 1400, unprocessed 1400 [2022-12-15 15:04:23] WARN mpeg/handle_mpeg_frame detected samplerate change to 32000 on �E T� [2022-12-15 15:04:23] WARN mpeg/handle_mpeg_frame detected samplerate change to 48000 on �E T� [2022-12-15 15:04:24] WARN format-mp3/validate_mpeg source /studio04.mp3, len 1400, unprocessed 1400 [2022-12-15 15:04:24] WARN format-mp3/validate_mpeg source /studio04.mp3, len 1400, unprocessed 2400

I suppose there is something wrong on the encoder's mp3 codec, but on version kh15 and kh10 the issue is not present.

Thanks for your support, Luca

On 10 Dec 2022, at 02:22, Karl Heyes @.***> wrote:

The kh16.1 update has all known fixes in at the moment. Without the specifics on what is actually in use at the time it's hard to say whether anything in particular is resolved. I've done a bunch of locking changes recently so hard to say whether that may resolve it (hardware quirks can exhibit in some situations more easily). If you want to try kh16.1 or rebuild kh15 with debug (make debug) and then I can look into it. Grabbing a core file from the crash may be helpful in such cases.

— Reply to this email directly, view it on GitHub https://github.com/karlheyes/icecast-kh/issues/364#issuecomment-1344963811, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAZO3GGMUWHURYSY545K2Z3WMPLLTANCNFSM5RJIJJFQ. You are receiving this because you were mentioned.

karlheyes commented 1 year ago

there is a kh16.1 tagged in github (https://github.com/karlheyes/icecast-kh/tags) if you can verify. The other messages are of interest. It's obviously an issue with some block sizing (for handling different bitrates of streams) Are you relaying that as I could do with duplicating it here. If it's from a source client then can you grab a sample that I could feed into icecast here?

karl.

luca066 commented 1 year ago

Hi Karl,

I installed kh16 and kh16.1 on the same server , running on two different ports. On kh16 I have the issue, on kh16.1 it seems to be ok. I have to say that the issue started after some hours of listening. Both Icecast instances get the stream from another Icecast server, so the source is the same.

I noted these messages about the sample rates: [2022-12-20 10:33:26] WARN format-mp3/validate_mpeg source /studiosonart01.mp3, len 1400, unprocessed 2400 [2022-12-20 10:33:31] WARN mpeg/handle_mpeg_frame detected samplerate change to 48000 on connection [2022-12-20 10:33:31] WARN mpeg/handle_mpeg_frame detected samplerate change to 44100 on connection [2022-12-20 10:33:32] WARN mpeg/handle_mpeg_frame detected samplerate change to 32000 on connection

You can listen the issue here: http://168.119.110.66/studiosonart01.mp3 http://168.119.110.66/studiosonart01.mp3 while here you can listen the kh16.1 stream: http://168.119.110.66:8090/studiosonart01.mp3 http://168.119.110.66:8090/studiosonart01.mp3

Luca

On 19 Dec 2022, at 02:53, Karl Heyes @.***> wrote:

there is a kh16.1 tagged in github (https://github.com/karlheyes/icecast-kh/tags https://github.com/karlheyes/icecast-kh/tags) if you can verify. The other messages are of interest. It's obviously an issue with some block sizing (for handling different bitrates of streams) Are you relaying that as I could do with duplicating it here. If it's from a source client then can you grab a sample that I could feed into icecast here?

karl.

— Reply to this email directly, view it on GitHub https://github.com/karlheyes/icecast-kh/issues/364#issuecomment-1356975802, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAZO3GFRVGHHECDEWME26S3WN65YTANCNFSM5RJIJJFQ. You are receiving this because you were mentioned.

karlheyes commented 1 year ago

Each frame does reference a samplerate so that message is detecting a frame difference from previous. It is reporting it as a number of players don't like that but others can happily switch. It can happen if a source switches the feed and it is different or it could be down to some unexpected data in the stream that messes up with the frame marker checks, think ID3, icy metadata or a relay switch over. Obviously any memory corruption within icecast itself could show in the buffers which is why I've have fixed the recent reported issues. The unprocessed messages are the one I want to get a handle on.

The master tree has the latest fixes in

karl