karlheyes / icecast-kh

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

KH21 stuck in boot loop #413

Closed BusterNeece closed 1 year ago

BusterNeece commented 1 year ago

We're testing out the newly released KH21 on some test installations, and we keep running into a boot loop that isn't logged, despite being at loglevel 4.

This is all we're seeing:

[2023-04-16  05:08:34] INFO thread/ lock abort set to 0
[2023-04-16  05:08:34] INFO logging/recheck_log_file Using log file /var/azuracast/stations/azuratest_radio/config/icecast_access.log
[2023-04-16  05:08:34] INFO main/server_proc_init Icecast 2.4.0-kh21 server reading configuration from /var/azuracast/stations/azuratest_radio/config/icecast.xml
[2023-04-16  05:08:34] INFO connection/get_ssl_certificate SSL certificate found at /var/azuracast/acme/ssl.crt
[2023-04-16  05:08:34] INFO connection/get_ssl_certificate SSL private key found at /var/azuracast/acme/ssl.key
[2023-04-16  05:08:34] INFO connection/get_ssl_certificate SSL using ciphers ECDH+AESGCM:DH+AESGCM:ECDH+AES256:DH+AES256:ECDH+AES128:DH+AES:RSA+AESGCM:RSA+AES:!aNULL:!MD5:!DSS
[2023-04-16  05:08:34] INFO connection/connection_setup_sockets 1 listener socket(s) for port 8000
[2023-04-16  05:08:34] INFO connection/connection_setup_sockets 1 listening sockets setup complete
[2023-04-16  05:08:34] INFO fserve/fserve_initialize file serving started
[2023-04-16  05:08:34] INFO main/server_process Icecast 2.4.0-kh21 server started
[2023-04-16  05:08:34] WARN slave/slave_startup process has 65536 max file descriptor limit
[2023-04-16  05:08:34] INFO client/workers_adjust requested worker count 1
[2023-04-16  05:08:34] INFO client/worker_start starting incoming worker thread 0x55fde10e03f0
[2023-04-16  05:08:34] DBUG yp/yp_recheck_config Updating YP configuration
[2023-04-16  05:08:34] INFO fserve/open_fh lookup of fallback file "/fallback-[64].mp3" (8000)
[2023-04-16  05:08:34] INFO format-mp3/format_mp3_get_plugin Created format details for /fallback-[64].mp3
[2023-04-16  05:08:34] DBUG format-mp3/format_mp3_apply_settings sending metadata interval 16000
[2023-04-16  05:08:34] DBUG format-mp3/format_mp3_apply_settings charset UTF-8
[2023-04-16  05:08:34] INFO mpeg/check_for_id3 Detected ID3v2 (4.0), tag size 1129 on /fallback-[64].mp3
[2023-04-16  05:08:34] INFO mpeg/check_for_mp3 MPEG 1 Layer 3 Detected (44100 2 64 kbps) on /fallback-[64].mp3
[2023-04-16  05:08:34] DBUG source/source_recheck_mounts fallback checking /mobile.mp3 (fallback has 0)
[2023-04-16  05:08:34] DBUG stats/stats_handle new source stat /mobile.mp3
[2023-04-16  05:08:34] DBUG stats/process_source_stat new node on /mobile.mp3 "listenurl" (http://demo.azuracast.com:8000/mobile.mp3)
[2023-04-16  05:08:34] DBUG stats/process_source_stat new node on /mobile.mp3 "listeners" (0)
[2023-04-16  05:08:34] DBUG stats/process_source_stat new node on /mobile.mp3 "max_listeners" (unlimited)
[2023-04-16  05:08:34] INFO fserve/open_fh lookup of fallback file "/fallback-[128].mp3" (16000)
[2023-04-16  05:08:34] INFO format-mp3/format_mp3_get_plugin Created format details for /fallback-[128].mp3
[2023-04-16  05:08:34] DBUG format-mp3/format_mp3_apply_settings sending metadata interval 16000
[2023-04-16  05:08:34] DBUG format-mp3/format_mp3_apply_settings charset UTF-8
[2023-04-16  05:08:34] INFO mpeg/check_for_id3 Detected ID3v2 (4.0), tag size 1129 on /fallback-[128].mp3
[2023-04-16  05:08:34] INFO mpeg/check_for_mp3 MPEG 1 Layer 3 Detected (44100 2 128 kbps) on /fallback-[128].mp3
[2023-04-16  05:08:34] DBUG source/source_recheck_mounts fallback checking /radio.mp3 (fallback has 0)
[2023-04-16  05:08:34] DBUG stats/stats_handle new source stat /radio.mp3
[2023-04-16  05:08:34] DBUG stats/process_source_stat new node on /radio.mp3 "listenurl" (http://demo.azuracast.com:8000/radio.mp3)
[2023-04-16  05:08:34] DBUG stats/process_source_stat new node on /radio.mp3 "listeners" (0)
[2023-04-16  05:08:34] DBUG stats/process_source_stat new node on /radio.mp3 "max_listeners" (unlimited)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global banned_IPs (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global client_connections (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global clients (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global connections (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global listener_connections (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global listeners (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global outgoing_kbitrate (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global source_client_connections (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global source_relay_connections (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global source_total_connections (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global sources (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global stats (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global stats_connections (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global stream_kbytes_read (0)
[2023-04-16  05:08:34] DBUG stats/stats_global_calc update global stream_kbytes_sent (0)
[2023-04-16  05:08:34] INFO connection/connection_thread connection thread started
[2023-04-16  05:08:34] DBUG client/worker 0x55fde10e0700 now has 0 clients
[2023-04-16  05:08:34] DBUG client/worker 0x55fde10e03f0 now has 0 clients
[2023-04-16  05:08:34] INFO client/log_commit_thread started

-- program crashes, restarts --

[2023-04-16  05:08:43] INFO thread/ lock abort set to 0
[2023-04-16  05:08:43] INFO logging/recheck_log_file Using log file /var/azuracast/stations/azuratest_radio/config/icecast_access.log
[2023-04-16  05:08:43] INFO main/server_proc_init Icecast 2.4.0-kh21 server reading configuration from /var/azuracast/stations/azuratest_radio/config/icecast.xml

...(repeating)

Happy to share any other details of our configurations as needed.

karlheyes commented 1 year ago

hmm, ok. well lets see where the crash point is. If you know how to get a core file or backtrace from a debug build then that will help. If not, then send me the xml (actual passwords are not important). The trigger may be the mp3 fallback for example but hard to tell from this. If you are not familiar with a core file handling then and easily reproducible then check if you have catchsegv and if not use gdb

(don't use -b in such cases as if can get confusing)

catchsegv .../icecast .......xml
gdb --args ../icecast ..../xml gdb> run crash... gdb> taas bt gdb> exit

you can post the output here or email.

karl

BusterNeece commented 1 year ago

@karlheyes It's been pretty intermittent, as a majority of the time the service will start up just fine, but it appears that I've managed to capture a segfault in action. In this case, it was Thread 2:

Thread 5 (Thread 0x7fbe8b6e3640 (LWP 18104) "icecast"):
#0  0x00007fbe8e69dd7f in __GI___poll (fds=fds@entry=0x7fbe8b6e2920, nfds=2, timeout=timeout@entry=4000) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x0000556eaf5e3d29 in poll (__timeout=4000, __nfds=<optimized out>, __fds=0x7fbe8b6e2920) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2  wait_for_serversock () at connection.c:981
#3  accept_client () at connection.c:1093
#4  connection_thread (arg=arg@entry=0x0) at connection.c:1537
#5  0x0000556eaf617681 in _start_routine (arg=0x556eb0ae2db0) at thread.c:768
#6  0x00007fbe8e619b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#7  0x00007fbe8e6aabb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

Thread 4 (Thread 0x7fbe8b7e4640 (LWP 18103) "icecast"):
--Type <RET> for more, q to quit, c to continue without paging--
#0  0x00007fbe8e69dd7f in __GI___poll (fds=fds@entry=0x7fbe8b7e39d0, nfds=nfds@entry=1, timeout=30000) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x0000556eaf5e48f2 in poll (__timeout=<optimized out>, __nfds=1, __fds=0x7fbe8b7e39d0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2  util_timed_wait_for_fd (fd=<optimized out>, timeout=<optimized out>) at util.c:96
#3  0x0000556eaf5f8649 in worker_wait (wc=wc@entry=0x7fbe8b7e3ae0) at client.c:644
#4  0x0000556eaf5f8a77 in worker (arg=arg@entry=0x556eb0aa8d40) at client.c:903
#5  0x0000556eaf617681 in _start_routine (arg=0x556eb0aa8e00) at thread.c:768
#6  0x00007fbe8e619b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#7  0x00007fbe8e6aabb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

Thread 3 (Thread 0x7fbe8b8e5640 (LWP 18102) "icecast"):
#0  0x00007fbe8e69dd7f in __GI___poll (fds=fds@entry=0x7fbe8b8e49d0, nfds=nfds@entry=1, timeout=30000) at ../sysdeps/unix/sysv/linux/poll.c:29
--Type <RET> for more, q to quit, c to continue without paging--
#1  0x0000556eaf5e48f2 in poll (__timeout=<optimized out>, __nfds=1, __fds=0x7fbe8b8e49d0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2  util_timed_wait_for_fd (fd=<optimized out>, timeout=<optimized out>) at util.c:96
#3  0x0000556eaf5f8649 in worker_wait (wc=wc@entry=0x7fbe8b8e4ae0) at client.c:644
#4  0x0000556eaf5f8a77 in worker (arg=arg@entry=0x556eb0aa8a30) at client.c:903
#5  0x0000556eaf617681 in _start_routine (arg=0x556eb0aa8af0) at thread.c:768
#6  0x00007fbe8e619b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#7  0x00007fbe8e6aabb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

Thread 2 (Thread 0x7fbe8b9e6640 (LWP 18101) "icecast"):
#0  malloc_consolidate (av=av@entry=0x7fbe84000030) at ./malloc/malloc.c:4753
#1  0x00007fbe8e628c5b in _int_malloc (av=av@entry=0x7fbe84000030, bytes=bytes@entry=4096) at ./malloc/malloc.c:3965
#2  0x00007fbe8e62a1b9 in __GI___libc_malloc (bytes=bytes@entry=4096) at ./malloc/malloc.c:3329
--Type <RET> for more, q to quit, c to continue without paging--
#3  0x00007fbe8e603c24 in __GI__IO_file_doallocate (fp=0x7fbe84000be0) at ./libio/filedoalloc.c:101
#4  0x00007fbe8e612d60 in __GI__IO_doallocbuf (fp=fp@entry=0x7fbe84000be0) at ./libio/libioP.h:947
#5  0x00007fbe8e611fe0 in _IO_new_file_overflow (f=0x7fbe84000be0, ch=-1) at ./libio/fileops.c:744
#6  0x00007fbe8e610755 in _IO_new_file_xsputn (n=206, data=<optimized out>, f=<optimized out>) at ./libio/libioP.h:947
#7  _IO_new_file_xsputn (f=0x7fbe84000be0, data=<optimized out>, n=206) at ./libio/fileops.c:1196
#8  0x00007fbe8e5fc08c in outstring_func (done=0, length=206, string=0x7fbe7c004ec0 "127.0.0.1 - admin [17/Apr/2023:01:17:41 +0000] \"GET /admin/listclients?mount=%2Fradio.mp3 HTTP/1.1\" 400 149 \"-\" \"Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.8.1.2) Gecko/20070219 Firefox/2.0."..., s=0x7fbe84000be0) at ../libio/libioP.h:947
--Type <RET> for more, q to quit, c to continue without paging--
#9  __vfprintf_internal (s=0x7fbe84000be0, format=0x556eaf62277f "%s%s\n", ap=ap@entry=0x7fbe8b9e5830, mode_flags=mode_flags@entry=2) at ./stdio-common/vfprintf-internal.c:1517
#10 0x00007fbe8e6b9ec3 in ___fprintf_chk (fp=<optimized out>, flag=flag@entry=1, format=format@entry=0x556eaf62277f "%s%s\n") at ./debug/fprintf_chk.c:33
#11 0x0000556eaf6198e9 in fprintf (__fmt=0x556eaf62277f "%s%s\n", __stream=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/stdio2.h:105
#12 do_log_run (log_id=log_id@entry=2) at log.c:553
#13 0x0000556eaf61aac3 in log_commit_entries () at log.c:579
#14 0x0000556eaf5f8487 in log_commit_thread (arg=arg@entry=0x0) at client.c:1060
#15 0x0000556eaf617681 in _start_routine (arg=0x556eb0aa8440) at thread.c:768
#16 0x00007fbe8e619b43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#17 0x00007fbe8e6aabb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

Thread 1 (Thread 0x7fbe8b9e9980 (LWP 18098) "icecast"):
--Type <RET> for more, q to quit, c to continue without paging--
#0  0x00007fbe8e66a868 in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=req@entry=0x7ffd87c97fd0, rem=rem@entry=0x7ffd87c97fe0) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
#1  0x00007fbe8e66f6e7 in __GI___nanosleep (req=req@entry=0x7ffd87c97fd0, rem=rem@entry=0x7ffd87c97fe0) at ../sysdeps/unix/sysv/linux/nanosleep.c:25
#2  0x0000556eaf61834d in thread_sleep (len=len@entry=1000000) at thread.c:728
#3  0x0000556eaf5ea537 in _slave_thread () at slave.c:1361
#4  slave_initialize () at slave.c:256
#5  0x0000556eaf5df03e in server_process () at main.c:237
#6  0x0000556eaf5d9263 in main (argc=3, argv=0x7ffd87c981e8) at main.c:436

The Icecast config is as follows:

<icecast>
    <location>AzuraCast</location>
    <admin>icemaster@localhost</admin>
    <hostname>azuracast.local</hostname>
    <limits>
        <clients>2500</clients>
        <sources>1</sources>
        <queue-size>524288</queue-size>
        <client-timeout>30</client-timeout>
        <header-timeout>15</header-timeout>
        <source-timeout>10</source-timeout>
        <burst-size>65535</burst-size>
    </limits>
    <authentication>
        <source-password>(PASSWORD)</source-password>
        <relay-password>(PASSWORD)</relay-password>
        <admin-user>admin</admin-user>
        <admin-password>(PASSWORD)</admin-password>
    </authentication>
    <listen-socket>
        <port>8000</port>
    </listen-socket>
    <mount type="normal">
        <mount-name>/radio.mp3</mount-name>
        <charset>UTF8</charset>
        <stream-name>AzuraTest Radio</stream-name>
        <fallback-mount>/fallback-[128].mp3</fallback-mount>
        <fallback-override>1</fallback-override>
    </mount>
    <fileserve>1</fileserve>
    <paths>
        <basedir>/usr/local/share/icecast</basedir>
        <logdir>/var/azuracast/stations/azuratest_radio/config</logdir>
        <webroot>/usr/local/share/icecast/web</webroot>
        <adminroot>/usr/local/share/icecast/admin</adminroot>
        <pidfile>/var/azuracast/stations/azuratest_radio/config/icecast.pid</pidfile>
        <alias source="/" dest="/status.xsl"/>
        <ssl-private-key>/var/azuracast/acme/ssl.key</ssl-private-key>
        <ssl-certificate>/var/azuracast/acme/ssl.crt</ssl-certificate>
        <ssl-allowed-ciphers>ECDH+AESGCM:DH+AESGCM:ECDH+AES256:DH+AES256:ECDH+AES128:DH+AES:RSA+AESGCM:RSA+AES:!aNULL:!MD5:!DSS</ssl-allowed-ciphers>
        <deny-ip>/var/azuracast/stations/azuratest_radio/config/ip_bans.txt</deny-ip>
        <deny-agents>/var/azuracast/stations/azuratest_radio/config/user_agent_bans.txt</deny-agents>
        <x-forwarded-for>127.0.0.1</x-forwarded-for>
    </paths>
    <logging>
        <accesslog>icecast_access.log</accesslog>
        <errorlog>/dev/stderr</errorlog>
        <loglevel>4</loglevel>
        <logsize>10000</logsize>
    </logging>
    <security>
        <chroot>0</chroot>
    </security>
</icecast>
BusterNeece commented 1 year ago

Seems like a call to /admin/listclients sets it off? That's pretty routine in AzuraCast's case as we pull listener metrics. It could be that such a call happening right as the service is starting up is causing it to fail?

karlheyes commented 1 year ago

I suspect the issue is memory corruption from a stats bug, the listclients call may just be a trigger but if easy to do then fine. I have fixed an issue which may be a factor here. Can you check the master tree with your setup to verify

karl

BusterNeece commented 1 year ago

Pulled down the latest commit and have been testing with it locally, and I've tried a few hundred times and can't get it to reproduce the segfault it was showing before. Will push out to our Rolling Release test users and see if we get any responses back, but it looks solid for now.

BusterNeece commented 1 year ago

@karlheyes Seems even on the latest release version, we're getting similar errors. It's hard for me to tell what specific situations prompt this error, but once it encounters this error condition, it basically locks up and refuses to start.

Here's another gdb trace, though it looks similar to the previous:

[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7f6f5930b640 (LWP 3371)]
[2023-04-20  10:35:50] WARN slave/slave_startup process has 65536 max file descriptor limit
[New Thread 0x7f6f5920a640 (LWP 3372)]
[New Thread 0x7f6f59109640 (LWP 3373)]
[New Thread 0x7f6f59008640 (LWP 3374)]

Thread 2 "icecast" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7f6f5930b640 (LWP 3371)]
malloc_consolidate (av=av@entry=0x7f6f54000030) at ./malloc/malloc.c:4753
4753    ./malloc/malloc.c: No such file or directory.
(gdb) taas bt

Thread 5 (Thread 0x7f6f59008640 (LWP 3374) "icecast"):
#0  0x00007f6f5bfc2d7f in __GI___poll (fds=fds@entry=0x7f6f59007920, nfds=2, timeout=timeout@entry=4000) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x0000559a1c214d89 in poll (__timeout=4000, __nfds=<optimized out>, __fds=0x7f6f59007920) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2  wait_for_serversock () at connection.c:981
#3  accept_client () at connection.c:1093
#4  connection_thread (arg=arg@entry=0x0) at connection.c:1537
#5  0x0000559a1c2486c1 in _start_routine (arg=0x559a1cc6dc60) at thread.c:768
#6  0x00007f6f5bf3eb43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#7  0x00007f6f5bfcfbb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

Thread 4 (Thread 0x7f6f59109640 (LWP 3373) "icecast"):
#0  0x00007f6f5bfc2d7f in __GI___poll (fds=fds@entry=0x7f6f591089d0, nfds=nfds@entry=1, timeout=30000) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x0000559a1c215952 in poll (__timeout=<optimized out>, __nfds=1, __fds=0x7f6f591089d0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2  util_timed_wait_for_fd (fd=<optimized out>, timeout=<optimized out>) at util.c:96
#3  0x0000559a1c229649 in worker_wait (wc=wc@entry=0x7f6f59108ae0) at client.c:644
#4  0x0000559a1c229a77 in worker (arg=arg@entry=0x559a1cc336c0) at client.c:903
#5  0x0000559a1c2486c1 in _start_routine (arg=0x559a1cc33780) at thread.c:768
#6  0x00007f6f5bf3eb43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#7  0x00007f6f5bfcfbb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

--Type <RET> for more, q to quit, c to continue without paging--
Thread 3 (Thread 0x7f6f5920a640 (LWP 3372) "icecast"):
#0  0x00007f6f5bfc2d7f in __GI___poll (fds=fds@entry=0x7f6f592099d0, nfds=nfds@entry=1, timeout=51) at ../sysdeps/unix/sysv/linux/poll.c:29
#1  0x0000559a1c215952 in poll (__timeout=<optimized out>, __nfds=1, __fds=0x7f6f592099d0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2  util_timed_wait_for_fd (fd=<optimized out>, timeout=<optimized out>) at util.c:96
#3  0x0000559a1c229649 in worker_wait (wc=wc@entry=0x7f6f59209ae0) at client.c:644
#4  0x0000559a1c229a77 in worker (arg=arg@entry=0x559a1cc333f0) at client.c:903
#5  0x0000559a1c2486c1 in _start_routine (arg=0x559a1cc334b0) at thread.c:768
#6  0x00007f6f5bf3eb43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#7  0x00007f6f5bfcfbb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

Thread 2 (Thread 0x7f6f5930b640 (LWP 3371) "icecast"):
#0  malloc_consolidate (av=av@entry=0x7f6f54000030) at ./malloc/malloc.c:4753
#1  0x00007f6f5bf4dc5b in _int_malloc (av=av@entry=0x7f6f54000030, bytes=bytes@entry=4096) at ./malloc/malloc.c:3965
#2  0x00007f6f5bf4f1b9 in __GI___libc_malloc (bytes=bytes@entry=4096) at ./malloc/malloc.c:3329
#3  0x00007f6f5bf28c24 in __GI__IO_file_doallocate (fp=0x7f6f54000be0) at ./libio/filedoalloc.c:101
#4  0x00007f6f5bf37d60 in __GI__IO_doallocbuf (fp=fp@entry=0x7f6f54000be0) at ./libio/libioP.h:947
#5  0x00007f6f5bf36fe0 in _IO_new_file_overflow (f=0x7f6f54000be0, ch=-1) at ./libio/fileops.c:744
#6  0x00007f6f5bf35755 in _IO_new_file_xsputn (n=182, data=<optimized out>, f=<optimized out>) at ./libio/libioP.h:947
#7  _IO_new_file_xsputn (f=0x7f6f54000be0, data=<optimized out>, n=182) at ./libio/fileops.c:1196
#8  0x00007f6f5bf2108c in outstring_func (done=0, length=182, string=0x7f6f4c00cf20 "127.0.0.1 - admin [20/Apr/2023:10:35:51 +0000] \"GET /admin/stats HTTP/1.1\" 200 3414 \"-\" \"Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US;--Type <RET> for more, q to quit, c to continue without paging--
 rv:1.8.1.2) Gecko/20070219 Firefox/2.0.0.2\" 0", s=0x7f6f54000be0) at ../libio/libioP.h:947
#9  __vfprintf_internal (s=0x7f6f54000be0, format=0x559a1c25375f "%s%s\n", ap=ap@entry=0x7f6f5930a870, mode_flags=mode_flags@entry=2) at ./stdio-common/vfprintf-internal.c:1517
#10 0x00007f6f5bfdeec3 in ___fprintf_chk (fp=<optimized out>, flag=flag@entry=1, format=format@entry=0x559a1c25375f "%s%s\n") at ./debug/fprintf_chk.c:33
#11 0x0000559a1c24a999 in fprintf (__fmt=0x559a1c25375f "%s%s\n", __stream=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/stdio2.h:105
#12 do_log_run (log_id=log_id@entry=2) at log.c:562
#13 0x0000559a1c24bb53 in log_commit_entries () at log.c:588
#14 0x0000559a1c229487 in log_commit_thread (arg=arg@entry=0x0) at client.c:1060
#15 0x0000559a1c2486c1 in _start_routine (arg=0x559a1cc32d80) at thread.c:768
#16 0x00007f6f5bf3eb43 in start_thread (arg=<optimized out>) at ./nptl/pthread_create.c:442
#17 0x00007f6f5bfcfbb4 in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:100

Thread 1 (Thread 0x7f6f5930e980 (LWP 3368) "icecast"):
#0  0x00007f6f5bf8f868 in __GI___clock_nanosleep (clock_id=clock_id@entry=0, flags=flags@entry=0, req=req@entry=0x7ffd69a19860, rem=rem@entry=0x7ffd69a19870) at ../sysdeps/unix/sysv/linux/clock_nanosleep.c:78
#1  0x00007f6f5bf946e7 in __GI___nanosleep (req=req@entry=0x7ffd69a19860, rem=rem@entry=0x7ffd69a19870) at ../sysdeps/unix/sysv/linux/nanosleep.c:25
#2  0x0000559a1c24938d in thread_sleep (len=len@entry=1000000) at thread.c:728
#3  0x0000559a1c21b597 in _slave_thread () at slave.c:1361
#4  slave_initialize () at slave.c:256
#5  0x0000559a1c21009e in server_process () at main.c:237
#6  0x0000559a1c20a263 in main (argc=3, argv=0x7ffd69a19a78) at main.c:436
Moonbase59 commented 1 year ago

I’m on AzuraCast Rolling Release #91742f4 (2023-04-20 5:51), and I can reproduce a segfault on every start:

cd /var/azuracast
./docker.sh bash
cd /var/azuracast/stations/testradio/config/
gdb --args /usr/local/bin/icecast -c ./icecast.xml

Reading symbols from /usr/local/bin/icecast...
(gdb) run
Starting program: /usr/local/bin/icecast -c ./icecast.xml
warning: Error disabling address space randomization: Operation not permitted
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
[New Thread 0x7f3050afc640 (LWP 2138)]
[2023-04-20  10:43:00] WARN slave/slave_startup process has 65536 max file descriptor limit
[New Thread 0x7f30509fb640 (LWP 2139)]
[New Thread 0x7f30508fa640 (LWP 2140)]
[New Thread 0x7f30507f9640 (LWP 2141)]

Thread 2 "icecast" received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7f3050afc640 (LWP 2138)]
0x00007f305373c91e in ?? () from /lib/x86_64-linux-gnu/libc.so.6

(gdb) taas bt

Thread 5 (Thread 0x7f30507f9640 (LWP 2141) "icecast"):
#0  0x00007f30537b3d7f in poll () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x0000555f72839d89 in poll (__timeout=4000, __nfds=<optimized out>, __fds=0x7f30507f8920) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2  wait_for_serversock () at connection.c:981
#3  accept_client () at connection.c:1093
#4  connection_thread (arg=arg@entry=0x0) at connection.c:1537
#5  0x0000555f7286d6c1 in _start_routine (arg=0x555f72cc5de0) at thread.c:768
#6  0x00007f305372fb43 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#7  0x00007f30537c0bb4 in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 4 (Thread 0x7f30508fa640 (LWP 2140) "icecast"):
#0  0x00007f30537b3d7f in poll () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x0000555f7283a952 in poll (__timeout=<optimized out>, __nfds=1, __fds=0x7f30508f99d0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2  util_timed_wait_for_fd (fd=<optimized out>, timeout=<optimized out>) at util.c:96
#3  0x0000555f7284e649 in worker_wait (wc=wc@entry=0x7f30508f9ae0) at client.c:644
#4  0x0000555f7284ea77 in worker (arg=arg@entry=0x555f72c8bcc0) at client.c:903
#5  0x0000555f7286d6c1 in _start_routine (arg=0x555f72c8bd80) at thread.c:768
#6  0x00007f305372fb43 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
--Type <RET> for more, q to quit, c to continue without paging--
#7  0x00007f30537c0bb4 in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 3 (Thread 0x7f30509fb640 (LWP 2139) "icecast"):
#0  0x00007f30537b3d7f in poll () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x0000555f7283a952 in poll (__timeout=<optimized out>, __nfds=1, __fds=0x7f30509fa9d0) at /usr/include/x86_64-linux-gnu/bits/poll2.h:39
#2  util_timed_wait_for_fd (fd=<optimized out>, timeout=<optimized out>) at util.c:96
#3  0x0000555f7284e649 in worker_wait (wc=wc@entry=0x7f30509faae0) at client.c:644
#4  0x0000555f7284ea77 in worker (arg=arg@entry=0x555f72c8b9f0) at client.c:903
#5  0x0000555f7286d6c1 in _start_routine (arg=0x555f72c8bab0) at thread.c:768
#6  0x00007f305372fb43 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#7  0x00007f30537c0bb4 in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 2 (Thread 0x7f3050afc640 (LWP 2138) "icecast"):
#0  0x00007f305373c91e in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007f305373ec5b in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x00007f30537401b9 in malloc () from /lib/x86_64-linux-gnu/libc.so.6
#3  0x00007f3053719c24 in _IO_file_doallocate () from /lib/x86_64-linux-gnu/libc.so.6
#4  0x00007f3053728d60 in _IO_doallocbuf () from /lib/x86_64-linux-gnu/libc.so.6
#5  0x00007f3053727fe0 in _IO_file_overflow () from /lib/x86_64-linux-gnu/libc.so.6
#6  0x00007f3053726755 in _IO_file_xsputn () from /lib/x86_64-linux-gnu/libc.so.6
#7  0x00007f305371208c in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#8  0x00007f30537cfec3 in __fprintf_chk () from /lib/x86_64-linux-gnu/libc.so.6
#9  0x0000555f7286f999 in fprintf (__fmt=0x555f7287875f "%s%s\n", __stream=<optimized out>) at /usr/include/x86_64-linux-gnu/bits/stdio2.h:105
#10 do_log_run (log_id=log_id@entry=2) at log.c:562
#11 0x0000555f72870b53 in log_commit_entries () at log.c:588
#12 0x0000555f7284e487 in log_commit_thread (arg=arg@entry=0x0) at client.c:1060
#13 0x0000555f7286d6c1 in _start_routine (arg=0x555f72c8b380) at thread.c:768
#14 0x00007f305372fb43 in ?? () from /lib/x86_64-linux-gnu/libc.so.6
#15 0x00007f30537c0bb4 in clone () from /lib/x86_64-linux-gnu/libc.so.6

Thread 1 (Thread 0x7f3050aff980 (LWP 2126) "icecast"):
#0  0x00007f3053780868 in clock_nanosleep () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007f30537856e7 in nanosleep () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x0000555f7286e38d in thread_sleep (len=len@entry=1000000) at thread.c:728
#3  0x0000555f72840597 in _slave_thread () at slave.c:1361
#4  slave_initialize () at slave.c:256
#5  0x0000555f7283509e in server_process () at main.c:237
#6  0x0000555f7282f263 in main (argc=3, argv=0x7ffc53f65c88) at main.c:436
(gdb) 

icecast.xml (passwords, domain name, station name changed):

<icecast>
    <location>AzuraCast</location>
    <admin>icemaster@localhost</admin>
    <hostname>radio.testradio.net</hostname>
    <limits>
        <clients>499</clients>
        <sources>2</sources>
        <queue-size>524288</queue-size>
        <client-timeout>30</client-timeout>
        <header-timeout>15</header-timeout>
        <source-timeout>10</source-timeout>
        <burst-size>65535</burst-size>
    </limits>
    <authentication>
        <source-password>(PASSWORD)</source-password>
        <relay-password>(PASSWORD)</relay-password>
        <admin-user>admin</admin-user>
        <admin-password>(PASSWORD)</admin-password>
    </authentication>
    <listen-socket>
        <port>8000</port>
    </listen-socket>
    <mount type="normal">
        <mount-name>/radio.mp3</mount-name>
        <charset>UTF8</charset>
        <stream-name>Test Radio</stream-name>
        <stream-description>Non-public test &amp; evaluation server only</stream-description>
        <stream-url>https://radio.testradio.net/public/testradio</stream-url>
        <genre>Various</genre>
        <intro>../../../../..//var/azuracast/stations/testradio/config/mount_1_intro.mp3</intro>
        <fallback-mount>/fallback-[128].mp3</fallback-mount>
        <fallback-override>1</fallback-override>
        <http-headers>
            <header name="icy-index-metadata" value="1"/>
            <header name="icy-version" value="2"/>
            <header name="icy-logo" value="https://radio.testradio.net/static/uploads/browser_icon/192.1678626043.png"/>
            <header name="icy-country-code" value="DE"/>
            <header name="icy-country-subdivision-code" value="DE-BY"/>
            <header name="icy-language-codes" value="deu,eng"/>
            <header name="icy-do-not-index" value="1"/>
        </http-headers>
    </mount>
    <mount type="normal">
        <mount-name>/radio.aac</mount-name>
        <charset>UTF8</charset>
        <stream-name>Test Radio</stream-name>
        <stream-description>Non-public test &amp; evaluation server only</stream-description>
        <stream-url>https://radio.testradio.net/public/testradio</stream-url>
        <genre>Various</genre>
        <intro>../../../../..//var/azuracast/stations/testradio/config/mount_3_intro.aac</intro>
        <fallback-mount>/error.mp3</fallback-mount>
        <fallback-override>1</fallback-override>
        <http-headers>
            <header name="icy-index-metadata" value="1"/>
            <header name="icy-version" value="2"/>
            <header name="icy-logo" value="https://radio.testradio.net/static/uploads/browser_icon/192.1678626043.png"/>
            <header name="icy-country-code" value="DE"/>
            <header name="icy-country-subdivision-code" value="DE-BY"/>
            <header name="icy-language-codes" value="deu,eng"/>
            <header name="icy-do-not-index" value="1"/>
        </http-headers>
    </mount>
    <fileserve>1</fileserve>
    <paths>
        <basedir>/usr/local/share/icecast</basedir>
        <logdir>/var/azuracast/stations/testradio/config</logdir>
        <webroot>/usr/local/share/icecast/web</webroot>
        <adminroot>/usr/local/share/icecast/admin</adminroot>
        <pidfile>/var/azuracast/stations/testradio/config/icecast.pid</pidfile>
        <alias source="/" dest="/status.xsl"/>
        <ssl-private-key>/var/azuracast/acme/ssl.key</ssl-private-key>
        <ssl-certificate>/var/azuracast/acme/ssl.crt</ssl-certificate>
        <ssl-allowed-ciphers>ECDH+AESGCM:DH+AESGCM:ECDH+AES256:DH+AES256:ECDH+AES128:DH+AES:RSA+AESGCM:RSA+AES:!aNULL:!MD5:!DSS</ssl-allowed-ciphers>
        <deny-ip>/var/azuracast/stations/testradio/config/ip_bans.txt</deny-ip>
        <deny-agents>/var/azuracast/stations/testradio/config/user_agent_bans.txt</deny-agents>
        <x-forwarded-for>127.0.0.1</x-forwarded-for>
    </paths>
    <logging>
        <accesslog>icecast_access.log</accesslog>
        <errorlog>/dev/stderr</errorlog>
        <loglevel>2</loglevel>
        <logsize>10000</logsize>
    </logging>
    <security>
        <chroot>0</chroot>
    </security>
</icecast>

Hope that helps a little further!

karlheyes commented 1 year ago

If you have an easily reproducible case then can you run it in valgrind and let me know of the issues it reports?

valgrind --log-file=/some/output/to/send -v .../icecast -c ..../xml

karl

BusterNeece commented 1 year ago

@karlheyes Here's mine from our demo installation:

==2249== Memcheck, a memory error detector
==2249== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==2249== Using Valgrind-3.18.1-42b08ed5bd-20211015 and LibVEX; rerun with -h for copyright info
==2249== Command: icecast -c /var/azuracast/stations/azuratest_radio/config/icecast.xml
==2249== Parent PID: 937
==2249==
--2249--
--2249-- Valgrind options:
--2249--    --log-file=./web/output.log
--2249--    -v
--2249-- Contents of /proc/version:
--2249--   Linux version 5.15.0-69-generic (buildd@lcy02-amd64-080) (gcc (Ubuntu 11.3.0-1ubuntu1~22.04) 11.3.0, GNU ld (GNU Binutils for Ubuntu) 2.38) #76-Ubuntu SMP Fri Mar 17 17:19:29 UTC 2023
--2249--
--2249-- Arch and hwcaps: AMD64, LittleEndian, amd64-cx16-lzcnt-rdtscp-sse3-ssse3-avx-avx2-bmi-f16c-rdrand
--2249-- Page sizes: currently 4096, max supported 4096
--2249-- Valgrind library directory: /usr/libexec/valgrind
--2249-- Reading syms from /usr/local/bin/icecast
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
--2249--   Considering /usr/lib/debug/.build-id/61/ef896a699bb1c2e4e231642b2e1688b2f1a61e.debug ..
--2249--   .. build-id is valid
--2249-- Reading syms from /usr/libexec/valgrind/memcheck-amd64-linux
--2249--    object doesn't have a symbol table
--2249--    object doesn't have a dynamic symbol table
--2249-- Scheduler: using generic scheduler lock implementation.
--2249-- Reading suppressions file: /usr/libexec/valgrind/default.supp
==2249== embedded gdbserver: reading from /tmp/vgdb-pipe-from-vgdb-to-2249-by-???-on-92f7a88ef991
==2249== embedded gdbserver: writing to   /tmp/vgdb-pipe-to-vgdb-from-2249-by-???-on-92f7a88ef991
==2249== embedded gdbserver: shared mem   /tmp/vgdb-pipe-shared-mem-vgdb-2249-by-???-on-92f7a88ef991
==2249==
==2249== TO CONTROL THIS PROCESS USING vgdb (which you probably
==2249== don't want to do, unless you know exactly what you're doing,
==2249== or are doing some strange experiment):
==2249==   /usr/bin/vgdb --pid=2249 ...command...
==2249==
==2249== TO DEBUG THIS PROCESS USING GDB: start GDB like this
==2249==   /path/to/gdb icecast
==2249== and then give GDB the following command
==2249==   target remote | /usr/bin/vgdb --pid=2249
==2249== --pid is optional if only one valgrind process is running
==2249==
--2249-- REDIR: 0x402aa60 (ld-linux-x86-64.so.2:strlen) redirected to 0x580bcec2 (???)
--2249-- REDIR: 0x402a830 (ld-linux-x86-64.so.2:index) redirected to 0x580bcedc (???)
--2249-- Reading syms from /usr/libexec/valgrind/vgpreload_core-amd64-linux.so
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so
--2249--    object doesn't have a symbol table
==2249== WARNING: new redirection conflicts with existing -- ignoring it
--2249--     old: 0x0402aa60 (strlen              ) R-> (0000.0) 0x580bcec2 ???
--2249--     new: 0x0402aa60 (strlen              ) R-> (2007.0) 0x0484ee30 strlen
--2249-- REDIR: 0x4027240 (ld-linux-x86-64.so.2:strcmp) redirected to 0x484fcd0 (strcmp)
--2249-- REDIR: 0x402afc0 (ld-linux-x86-64.so.2:mempcpy) redirected to 0x4853840 (mempcpy)
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libssl.so.3
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libcrypto.so.3
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libcurl.so.4.7.0
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libvorbis.so.0.4.9
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libogg.so.0.8.5
--2249--   Considering /usr/lib/x86_64-linux-gnu/libogg.so.0.8.5 ..
--2249--   .. CRC mismatch (computed 2f010366 wanted 3991f6dc)
--2249--   Considering /lib/x86_64-linux-gnu/libogg.so.0.8.5 ..
--2249--   .. CRC mismatch (computed 2f010366 wanted 3991f6dc)
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libxslt.so.1.1.34
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libxml2.so.2.9.13
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libc.so.6
--2249--   Considering /usr/lib/debug/.build-id/69/389d485a9793dbe873f0ea2c93e02efaa9aa3d.debug ..
--2249--   .. build-id is valid
==2249== WARNING: new redirection conflicts with existing -- ignoring it
--2249--     old: 0x050f4ce0 (memalign            ) R-> (1011.0) 0x0484e080 memalign
--2249--     new: 0x050f4ce0 (memalign            ) R-> (1017.0) 0x0484e050 aligned_alloc
==2249== WARNING: new redirection conflicts with existing -- ignoring it
--2249--     old: 0x050f4ce0 (memalign            ) R-> (1011.0) 0x0484e080 memalign
--2249--     new: 0x050f4ce0 (memalign            ) R-> (1017.0) 0x0484e020 aligned_alloc
==2249== WARNING: new redirection conflicts with existing -- ignoring it
--2249--     old: 0x050f4ce0 (memalign            ) R-> (1011.0) 0x0484e080 memalign
--2249--     new: 0x050f4ce0 (memalign            ) R-> (1017.0) 0x0484e050 aligned_alloc
==2249== WARNING: new redirection conflicts with existing -- ignoring it
--2249--     old: 0x050f4ce0 (memalign            ) R-> (1011.0) 0x0484e080 memalign
--2249--     new: 0x050f4ce0 (memalign            ) R-> (1017.0) 0x0484e020 aligned_alloc
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libnghttp2.so.14.20.1
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libidn2.so.0.3.7
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/librtmp.so.1
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libssh.so.4.8.7
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libpsl.so.5.3.2
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libgssapi_krb5.so.2.2
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libldap-2.5.so.0.1.9
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/liblber-2.5.so.0.1.9
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libzstd.so.1.4.8
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libbrotlidec.so.1.0.9
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libz.so.1.2.11
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libm.so.6
--2249--   Considering /usr/lib/debug/.build-id/27/e82301dba6c3f644404d504e1bb1c97894b433.debug ..
--2249--   .. build-id is valid
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libicuuc.so.70.1
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/liblzma.so.5.2.5
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libunistring.so.2.2.0
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libgnutls.so.30.31.0
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libhogweed.so.6.4
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libnettle.so.8.4
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libgmp.so.10.4.1
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libkrb5.so.3.3
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libk5crypto.so.3.1
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libcom_err.so.2.1
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libkrb5support.so.0.1
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libsasl2.so.2.0.25
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libbrotlicommon.so.1.0.9
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libicudata.so.70.1
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.30
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libgcc_s.so.1
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libp11-kit.so.0.3.0
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libtasn1.so.6.6.2
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libkeyutils.so.1.9
--2249--    object doesn't have a symbol table
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libresolv.so.2
--2249--   Considering /usr/lib/debug/.build-id/7f/d7253c61aa6fce2b7e13851c15afa14a5ab160.debug ..
--2249--   .. build-id is valid
--2249-- Reading syms from /usr/lib/x86_64-linux-gnu/libffi.so.8.1.0
--2249--    object doesn't have a symbol table
--2249-- REDIR: 0x50f77a0 (libc.so.6:strnlen) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f7a60 (libc.so.6:strpbrk) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f7360 (libc.so.6:strcmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x5115d50 (libc.so.6:wcsnlen) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8750 (libc.so.6:memset) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x51145c0 (libc.so.6:wcslen) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8c90 (libc.so.6:memcpy@@GLIBC_2.14) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x51143f0 (libc.so.6:wcschr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f72e0 (libc.so.6:index) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f79e0 (libc.so.6:rindex) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8620 (libc.so.6:memmove) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
==2249== Preferring higher priority redirection:
--2249--     old: 0x051ef940 (__memcpy_avx_unalign) R-> (2018.0) 0x04850f90 __memcpy_avx_unaligned_erms
--2249--     new: 0x051ef940 (__memcpy_avx_unalign) R-> (2018.1) 0x04852880 memmove
--2249-- REDIR: 0x5114470 (libc.so.6:wcscmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8a60 (libc.so.6:stpncpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x5114a30 (libc.so.6:wmemchr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f78b0 (libc.so.6:strncmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8af0 (libc.so.6:strcasecmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f74a0 (libc.so.6:strcspn) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x51144f0 (libc.so.6:wcscpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f7250 (libc.so.6:strcat) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8be0 (libc.so.6:strncasecmp_l) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8500 (libc.so.6:bcmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x51005f0 (libc.so.6:memrchr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50fa090 (libc.so.6:strchrnul) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f7410 (libc.so.6:strcpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8b90 (libc.so.6:strcasecmp_l) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f7720 (libc.so.6:strlen) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f7950 (libc.so.6:strncpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f89d0 (libc.so.6:stpcpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8470 (libc.so.6:memchr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f7b80 (libc.so.6:strspn) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8850 (libc.so.6:mempcpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8b40 (libc.so.6:strncasecmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50fa000 (libc.so.6:rawmemchr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f7820 (libc.so.6:strncat) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x5183430 (libc.so.6:__memcpy_chk) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x50f8390 (libc.so.6:strstr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--2249-- REDIR: 0x5183560 (libc.so.6:__memmove_chk) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
==2249== WARNING: new redirection conflicts with existing -- ignoring it
--2249--     old: 0x051ef910 (__memcpy_chk_avx_una) R-> (2030.0) 0x04853940 __memcpy_chk
--2249--     new: 0x051ef910 (__memcpy_chk_avx_una) R-> (2024.0) 0x048532c0 __memmove_chk
==2249== WARNING: new redirection conflicts with existing -- ignoring it
--2249--     old: 0x051ef910 (__memcpy_chk_avx_una) R-> (2030.0) 0x04853940 __memcpy_chk
--2249--     new: 0x051ef910 (__memcpy_chk_avx_una) R-> (2024.0) 0x048532c0 __memmove_chk
==2249== WARNING: new redirection conflicts with existing -- ignoring it
--2249--     old: 0x051ef910 (__memcpy_chk_avx_una) R-> (2030.0) 0x04853940 __memcpy_chk
--2249--     new: 0x051ef910 (__memcpy_chk_avx_una) R-> (2024.0) 0x048532c0 __memmove_chk
==2249== WARNING: new redirection conflicts with existing -- ignoring it
--2249--     old: 0x051ef910 (__memcpy_chk_avx_una) R-> (2030.0) 0x04853940 __memcpy_chk
--2249--     new: 0x051ef910 (__memcpy_chk_avx_una) R-> (2024.0) 0x048532c0 __memmove_chk
--2249-- REDIR: 0x51ec790 (libc.so.6:__strrchr_avx2) redirected to 0x484e810 (rindex)
--2249-- REDIR: 0x51ec960 (libc.so.6:__strlen_avx2) redirected to 0x484ed10 (strlen)
--2249-- REDIR: 0x51ec300 (libc.so.6:__strchr_avx2) redirected to 0x484e9f0 (index)
--2249-- REDIR: 0x51e7ac0 (libc.so.6:__strcmp_avx2) redirected to 0x484fbd0 (strcmp)
--2249-- REDIR: 0x50f4120 (libc.so.6:malloc) redirected to 0x4848820 (malloc)
--2249-- REDIR: 0x51e8c00 (libc.so.6:__memcmp_avx2_movbe) redirected to 0x4852010 (bcmp)
--2249-- REDIR: 0x51ef940 (libc.so.6:__memcpy_avx_unaligned_erms) redirected to 0x4852880 (memmove)
--2249-- REDIR: 0x50f55a0 (libc.so.6:calloc) redirected to 0x484d9d0 (calloc)
--2249-- REDIR: 0x51ef910 (libc.so.6:__memcpy_chk_avx_unaligned_erms) redirected to 0x4853940 (__memcpy_chk)
--2249-- REDIR: 0x50f4460 (libc.so.6:free) redirected to 0x484b210 (free)
--2249-- REDIR: 0x51f0100 (libc.so.6:__memset_avx2_unaligned_erms) redirected to 0x4852770 (memset)
--2249-- REDIR: 0x50f47c0 (libc.so.6:realloc) redirected to 0x484dc50 (realloc)
--2249-- REDIR: 0x51e7f00 (libc.so.6:__strncmp_avx2) redirected to 0x484f3e0 (strncmp)
--2249-- REDIR: 0x50f8040 (libc.so.6:__GI_strstr) redirected to 0x4853ae0 (__strstr_sse2)
--2249-- REDIR: 0x51e8440 (libc.so.6:__memchr_avx2) redirected to 0x484fd50 (memchr)
--2249-- REDIR: 0x51ec580 (libc.so.6:__strchrnul_avx2) redirected to 0x4853330 (strchrnul)
--2249-- REDIR: 0x51ea930 (libc.so.6:__strncasecmp_avx) redirected to 0x484f640 (strncasecmp)
--2249-- REDIR: 0x51e7870 (libc.so.6:__strpbrk_sse42) redirected to 0x4853c00 (strpbrk)
--2249-- REDIR: 0x51ede30 (libc.so.6:__strcpy_avx2) redirected to 0x484ee60 (strcpy)
--2249-- REDIR: 0x51ee1c0 (libc.so.6:__strncpy_avx2) redirected to 0x484efe0 (strncpy)
--2249-- REDIR: 0x51e92b0 (libc.so.6:__strcasecmp_avx) redirected to 0x484f560 (strcasecmp)
--2249-- REDIR: 0x51ef900 (libc.so.6:__mempcpy_avx_unaligned_erms) redirected to 0x4853440 (mempcpy)
--2249-- REDIR: 0x51e8710 (libc.so.6:__rawmemchr_avx2) redirected to 0x4853360 (rawmemchr)
--2249-- REDIR: 0x51e7730 (libc.so.6:__strcspn_sse42) redirected to 0x4853c70 (strcspn)
==2249== Thread 2:
==2249== Conditional jump or move depends on uninitialised value(s)
==2249==    at 0x1508C6: do_log_run (log.c:532)
==2249==    by 0x150E3E: _log_open (log.c:166)
==2249==    by 0x150910: do_log_run (log.c:550)
==2249==    by 0x151B52: log_commit_entries (log.c:588)
==2249==    by 0x12F486: log_commit_thread (client.c:1060)
==2249==    by 0x14E6C0: _start_routine (thread.c:768)
==2249==    by 0x50E3B42: start_thread (pthread_create.c:442)
==2249==    by 0x5174BB3: clone (clone.S:100)
==2249==
==2249== Thread 1:
==2249== Invalid write of size 8
==2249==    at 0x150ECD: create_log_entry (log.c:656)
==2249==    by 0x151FF9: log_write (log.c:741)
==2249==    by 0x14A64E: yp_recheck_config (yp.c:295)
==2249==    by 0x14AA07: yp_initialize (yp.c:361)
==2249==    by 0x12151E: slave_startup (slave.c:1262)
==2249==    by 0x12151E: _slave_thread (slave.c:1272)
==2249==    by 0x12151E: slave_initialize (slave.c:256)
==2249==    by 0x11609D: server_process (main.c:237)
==2249==    by 0x110262: main (main.c:436)
==2249==  Address 0x816b990 is 0 bytes inside a block of size 48 free'd
==2249==    at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==2249==    by 0x150B37: _log_close_internal.part.0 (log.c:432)
==2249==    by 0x150A32: _log_close_internal (log.c:411)
==2249==    by 0x150A32: do_log_run (log.c:573)
==2249==    by 0x151B52: log_commit_entries (log.c:588)
==2249==    by 0x12F486: log_commit_thread (client.c:1060)
==2249==    by 0x14E6C0: _start_routine (thread.c:768)
==2249==    by 0x50E3B42: start_thread (pthread_create.c:442)
==2249==    by 0x5174BB3: clone (clone.S:100)
==2249==  Block was alloc'd at
==2249==    at 0x484DA83: calloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==2249==    by 0x150E70: create_log_entry (log.c:633)
==2249==    by 0x151FF9: log_write (log.c:741)
==2249==    by 0x12FA0C: worker (client.c:894)
==2249==    by 0x14E6C0: _start_routine (thread.c:768)
==2249==    by 0x50E3B42: start_thread (pthread_create.c:442)
==2249==    by 0x5174BB3: clone (clone.S:100)
==2249==
--2249-- REDIR: 0x5113200 (libc.so.6:__strstr_sse2_unaligned) redirected to 0x4853a50 (strstr)
--2249-- REDIR: 0x51ecae0 (libc.so.6:__strnlen_avx2) redirected to 0x484ecb0 (strnlen)
==2249==
==2249== HEAP SUMMARY:
==2249==     in use at exit: 45,064 bytes in 876 blocks
==2249==   total heap usage: 26,377 allocs, 25,501 frees, 2,889,630 bytes allocated
==2249==
==2249== Searching for pointers to 876 not-freed blocks
==2249== Checked 513,560 bytes
==2249==
==2249== LEAK SUMMARY:
==2249==    definitely lost: 48 bytes in 1 blocks
==2249==    indirectly lost: 39,216 bytes in 671 blocks
==2249==      possibly lost: 0 bytes in 0 blocks
==2249==    still reachable: 5,800 bytes in 204 blocks
==2249==         suppressed: 0 bytes in 0 blocks
==2249== Rerun with --leak-check=full to see details of leaked memory
==2249==
==2249== Use --track-origins=yes to see where uninitialised values come from
==2249== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 0 from 0)
==2249==
==2249== 1 errors in context 1 of 2:
==2249== Invalid write of size 8
==2249==    at 0x150ECD: create_log_entry (log.c:656)
==2249==    by 0x151FF9: log_write (log.c:741)
==2249==    by 0x14A64E: yp_recheck_config (yp.c:295)
==2249==    by 0x14AA07: yp_initialize (yp.c:361)
==2249==    by 0x12151E: slave_startup (slave.c:1262)
==2249==    by 0x12151E: _slave_thread (slave.c:1272)
==2249==    by 0x12151E: slave_initialize (slave.c:256)
==2249==    by 0x11609D: server_process (main.c:237)
==2249==    by 0x110262: main (main.c:436)
==2249==  Address 0x816b990 is 0 bytes inside a block of size 48 free'd
==2249==    at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==2249==    by 0x150B37: _log_close_internal.part.0 (log.c:432)
==2249==    by 0x150A32: _log_close_internal (log.c:411)
==2249==    by 0x150A32: do_log_run (log.c:573)
==2249==    by 0x151B52: log_commit_entries (log.c:588)
==2249==    by 0x12F486: log_commit_thread (client.c:1060)
==2249==    by 0x14E6C0: _start_routine (thread.c:768)
==2249==    by 0x50E3B42: start_thread (pthread_create.c:442)
==2249==    by 0x5174BB3: clone (clone.S:100)
==2249==  Block was alloc'd at
==2249==    at 0x484DA83: calloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==2249==    by 0x150E70: create_log_entry (log.c:633)
==2249==    by 0x151FF9: log_write (log.c:741)
==2249==    by 0x12FA0C: worker (client.c:894)
==2249==    by 0x14E6C0: _start_routine (thread.c:768)
==2249==    by 0x50E3B42: start_thread (pthread_create.c:442)
==2249==    by 0x5174BB3: clone (clone.S:100)
==2249==
==2249==
==2249== 1 errors in context 2 of 2:
==2249== Thread 2:
==2249== Conditional jump or move depends on uninitialised value(s)
==2249==    at 0x1508C6: do_log_run (log.c:532)
==2249==    by 0x150E3E: _log_open (log.c:166)
==2249==    by 0x150910: do_log_run (log.c:550)
==2249==    by 0x151B52: log_commit_entries (log.c:588)
==2249==    by 0x12F486: log_commit_thread (client.c:1060)
==2249==    by 0x14E6C0: _start_routine (thread.c:768)
==2249==    by 0x50E3B42: start_thread (pthread_create.c:442)
==2249==    by 0x5174BB3: clone (clone.S:100)
==2249==
==2249== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 0 from 0)
Moonbase59 commented 1 year ago

And here’s mine:

==1765== Memcheck, a memory error detector
==1765== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==1765== Using Valgrind-3.18.1-42b08ed5bd-20211015 and LibVEX; rerun with -h for copyright info
==1765== Command: /usr/local/bin/icecast -c ./icecast.xml
==1765== Parent PID: 610
==1765== 
--1765-- 
--1765-- Valgrind options:
--1765--    --log-file=/tmp/valgrind-icecast.log
--1765--    -v
--1765-- Contents of /proc/version:
--1765--   Linux version 5.15.0-70-generic (buildd@lcy02-amd64-056) (gcc (Ubuntu 11.3.0-1ubuntu1~22.04) 11.3.0, GNU ld (GNU Binutils for Ubuntu) 2.38) #77-Ubuntu SMP Tue Mar 21 14:02:37 UTC 2023
--1765-- 
--1765-- Arch and hwcaps: AMD64, LittleEndian, amd64-cx16-sse3
--1765-- Page sizes: currently 4096, max supported 4096
--1765-- Valgrind library directory: /usr/libexec/valgrind
--1765-- Reading syms from /usr/local/bin/icecast
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/ld-linux-x86-64.so.2
--1765--   Considering /usr/lib/debug/.build-id/61/ef896a699bb1c2e4e231642b2e1688b2f1a61e.debug ..
--1765--   .. build-id is valid
--1765-- Reading syms from /usr/libexec/valgrind/memcheck-amd64-linux
--1765--    object doesn't have a symbol table
--1765--    object doesn't have a dynamic symbol table
--1765-- Scheduler: using generic scheduler lock implementation.
--1765-- Reading suppressions file: /usr/libexec/valgrind/default.supp
==1765== embedded gdbserver: reading from /tmp/vgdb-pipe-from-vgdb-to-1765-by-???-on-1726645f899c
==1765== embedded gdbserver: writing to   /tmp/vgdb-pipe-to-vgdb-from-1765-by-???-on-1726645f899c
==1765== embedded gdbserver: shared mem   /tmp/vgdb-pipe-shared-mem-vgdb-1765-by-???-on-1726645f899c
==1765== 
==1765== TO CONTROL THIS PROCESS USING vgdb (which you probably
==1765== don't want to do, unless you know exactly what you're doing,
==1765== or are doing some strange experiment):
==1765==   /usr/bin/vgdb --pid=1765 ...command...
==1765== 
==1765== TO DEBUG THIS PROCESS USING GDB: start GDB like this
==1765==   /path/to/gdb /usr/local/bin/icecast
==1765== and then give GDB the following command
==1765==   target remote | /usr/bin/vgdb --pid=1765
==1765== --pid is optional if only one valgrind process is running
==1765== 
--1765-- REDIR: 0x402aa60 (ld-linux-x86-64.so.2:strlen) redirected to 0x580bcec2 (???)
--1765-- REDIR: 0x402a830 (ld-linux-x86-64.so.2:index) redirected to 0x580bcedc (???)
--1765-- Reading syms from /usr/libexec/valgrind/vgpreload_core-amd64-linux.so
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so
--1765--    object doesn't have a symbol table
==1765== WARNING: new redirection conflicts with existing -- ignoring it
--1765--     old: 0x0402aa60 (strlen              ) R-> (0000.0) 0x580bcec2 ???
--1765--     new: 0x0402aa60 (strlen              ) R-> (2007.0) 0x0484ee30 strlen
--1765-- REDIR: 0x4027240 (ld-linux-x86-64.so.2:strcmp) redirected to 0x484fcd0 (strcmp)
--1765-- REDIR: 0x402afc0 (ld-linux-x86-64.so.2:mempcpy) redirected to 0x4853840 (mempcpy)
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libssl.so.3
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libcrypto.so.3
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libcurl.so.4.7.0
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libvorbis.so.0.4.9
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libogg.so.0.8.5
--1765--   Considering /usr/lib/x86_64-linux-gnu/libogg.so.0.8.5 ..
--1765--   .. CRC mismatch (computed 2f010366 wanted 3991f6dc)
--1765--   Considering /lib/x86_64-linux-gnu/libogg.so.0.8.5 ..
--1765--   .. CRC mismatch (computed 2f010366 wanted 3991f6dc)
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libxslt.so.1.1.34
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libxml2.so.2.9.13
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libc.so.6
--1765--   Considering /usr/lib/debug/.build-id/69/389d485a9793dbe873f0ea2c93e02efaa9aa3d.debug ..
--1765--   .. build-id is valid
==1765== WARNING: new redirection conflicts with existing -- ignoring it
--1765--     old: 0x050f4ce0 (memalign            ) R-> (1011.0) 0x0484e080 memalign
--1765--     new: 0x050f4ce0 (memalign            ) R-> (1017.0) 0x0484e050 aligned_alloc
==1765== WARNING: new redirection conflicts with existing -- ignoring it
--1765--     old: 0x050f4ce0 (memalign            ) R-> (1011.0) 0x0484e080 memalign
--1765--     new: 0x050f4ce0 (memalign            ) R-> (1017.0) 0x0484e020 aligned_alloc
==1765== WARNING: new redirection conflicts with existing -- ignoring it
--1765--     old: 0x050f4ce0 (memalign            ) R-> (1011.0) 0x0484e080 memalign
--1765--     new: 0x050f4ce0 (memalign            ) R-> (1017.0) 0x0484e050 aligned_alloc
==1765== WARNING: new redirection conflicts with existing -- ignoring it
--1765--     old: 0x050f4ce0 (memalign            ) R-> (1011.0) 0x0484e080 memalign
--1765--     new: 0x050f4ce0 (memalign            ) R-> (1017.0) 0x0484e020 aligned_alloc
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libnghttp2.so.14.20.1
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libidn2.so.0.3.7
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/librtmp.so.1
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libssh.so.4.8.7
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libpsl.so.5.3.2
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libgssapi_krb5.so.2.2
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libldap-2.5.so.0.1.9
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/liblber-2.5.so.0.1.9
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libzstd.so.1.4.8
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libbrotlidec.so.1.0.9
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libz.so.1.2.11
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libm.so.6
--1765--   Considering /usr/lib/debug/.build-id/27/e82301dba6c3f644404d504e1bb1c97894b433.debug ..
--1765--   .. build-id is valid
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libicuuc.so.70.1
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/liblzma.so.5.2.5
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libunistring.so.2.2.0
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libgnutls.so.30.31.0
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libhogweed.so.6.4
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libnettle.so.8.4
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libgmp.so.10.4.1
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libkrb5.so.3.3
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libk5crypto.so.3.1
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libcom_err.so.2.1
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libkrb5support.so.0.1
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libsasl2.so.2.0.25
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libbrotlicommon.so.1.0.9
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libicudata.so.70.1
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libstdc++.so.6.0.30
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libgcc_s.so.1
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libp11-kit.so.0.3.0
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libtasn1.so.6.6.2
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libkeyutils.so.1.9
--1765--    object doesn't have a symbol table
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libresolv.so.2
--1765--   Considering /usr/lib/debug/.build-id/7f/d7253c61aa6fce2b7e13851c15afa14a5ab160.debug ..
--1765--   .. build-id is valid
--1765-- Reading syms from /usr/lib/x86_64-linux-gnu/libffi.so.8.1.0
--1765--    object doesn't have a symbol table
--1765-- REDIR: 0x50f77a0 (libc.so.6:strnlen) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f7a60 (libc.so.6:strpbrk) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f7360 (libc.so.6:strcmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x5115d50 (libc.so.6:wcsnlen) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8750 (libc.so.6:memset) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x51145c0 (libc.so.6:wcslen) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8c90 (libc.so.6:memcpy@@GLIBC_2.14) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x51143f0 (libc.so.6:wcschr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f72e0 (libc.so.6:index) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f79e0 (libc.so.6:rindex) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8620 (libc.so.6:memmove) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x5114470 (libc.so.6:wcscmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8a60 (libc.so.6:stpncpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x5114a30 (libc.so.6:wmemchr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f78b0 (libc.so.6:strncmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8af0 (libc.so.6:strcasecmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f74a0 (libc.so.6:strcspn) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x51144f0 (libc.so.6:wcscpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f7250 (libc.so.6:strcat) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8be0 (libc.so.6:strncasecmp_l) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8500 (libc.so.6:bcmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x51005f0 (libc.so.6:memrchr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50fa090 (libc.so.6:strchrnul) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f7410 (libc.so.6:strcpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8b90 (libc.so.6:strcasecmp_l) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f7720 (libc.so.6:strlen) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f7950 (libc.so.6:strncpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f89d0 (libc.so.6:stpcpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8470 (libc.so.6:memchr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f7b80 (libc.so.6:strspn) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8850 (libc.so.6:mempcpy) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8b40 (libc.so.6:strncasecmp) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50fa000 (libc.so.6:rawmemchr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f7820 (libc.so.6:strncat) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x5183430 (libc.so.6:__memcpy_chk) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x50f8390 (libc.so.6:strstr) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
--1765-- REDIR: 0x5183560 (libc.so.6:__memmove_chk) redirected to 0x483f220 (_vgnU_ifunc_wrapper)
==1765== WARNING: new redirection conflicts with existing -- ignoring it
--1765--     old: 0x051138e0 (__memcpy_chk_sse2_un) R-> (2030.0) 0x04853940 __memcpy_chk
--1765--     new: 0x051138e0 (__memcpy_chk_sse2_un) R-> (2024.0) 0x048532c0 __memmove_chk
==1765== WARNING: new redirection conflicts with existing -- ignoring it
--1765--     old: 0x051138e0 (__memcpy_chk_sse2_un) R-> (2030.0) 0x04853940 __memcpy_chk
--1765--     new: 0x051138e0 (__memcpy_chk_sse2_un) R-> (2024.0) 0x048532c0 __memmove_chk
==1765== WARNING: new redirection conflicts with existing -- ignoring it
--1765--     old: 0x051138e0 (__memcpy_chk_sse2_un) R-> (2030.0) 0x04853940 __memcpy_chk
--1765--     new: 0x051138e0 (__memcpy_chk_sse2_un) R-> (2024.0) 0x048532c0 __memmove_chk
==1765== WARNING: new redirection conflicts with existing -- ignoring it
--1765--     old: 0x051138e0 (__memcpy_chk_sse2_un) R-> (2030.0) 0x04853940 __memcpy_chk
--1765--     new: 0x051138e0 (__memcpy_chk_sse2_un) R-> (2024.0) 0x048532c0 __memmove_chk
--1765-- REDIR: 0x51096d0 (libc.so.6:__strrchr_sse2) redirected to 0x484e870 (__strrchr_sse2)
--1765-- REDIR: 0x51099d0 (libc.so.6:__strlen_sse2) redirected to 0x484ed70 (__strlen_sse2)
--1765-- REDIR: 0x5109290 (libc.so.6:__strchr_sse2) redirected to 0x484e990 (__strchr_sse2)
--1765-- REDIR: 0x51009a0 (libc.so.6:__strcmp_sse2) redirected to 0x484fc50 (__strcmp_sse2)
--1765-- REDIR: 0x50f4120 (libc.so.6:malloc) redirected to 0x4848820 (malloc)
--1765-- REDIR: 0x5104210 (libc.so.6:__memcmp_sse2) redirected to 0x4851ef0 (__memcmp_sse2)
--1765-- REDIR: 0x51138f0 (libc.so.6:memcpy@GLIBC_2.2.5) redirected to 0x484fe00 (memcpy@GLIBC_2.2.5)
--1765-- REDIR: 0x50f55a0 (libc.so.6:calloc) redirected to 0x484d9d0 (calloc)
--1765-- REDIR: 0x51138e0 (libc.so.6:__memcpy_chk_sse2_unaligned) redirected to 0x4853940 (__memcpy_chk)
--1765-- REDIR: 0x50f4460 (libc.so.6:free) redirected to 0x484b210 (free)
--1765-- REDIR: 0x5113fe0 (libc.so.6:__memset_sse2_unaligned) redirected to 0x4852770 (memset)
--1765-- REDIR: 0x50f47c0 (libc.so.6:realloc) redirected to 0x484dc50 (realloc)
--1765-- REDIR: 0x51020a0 (libc.so.6:__strncmp_sse2) redirected to 0x484f4a0 (__strncmp_sse2)
--1765-- REDIR: 0x50f8040 (libc.so.6:__GI_strstr) redirected to 0x4853ae0 (__strstr_sse2)
--1765-- REDIR: 0x5103900 (libc.so.6:__memchr_sse2) redirected to 0x484fd50 (memchr)
--1765-- REDIR: 0x51094c0 (libc.so.6:__strchrnul_sse2) redirected to 0x4853330 (strchrnul)
--1765-- REDIR: 0x5106c30 (libc.so.6:__strncasecmp_sse2) redirected to 0x484f640 (strncasecmp)
--1765-- REDIR: 0x5113750 (libc.so.6:__strpbrk_sse2) redirected to 0x4853c00 (strpbrk)
--1765-- REDIR: 0x510e730 (libc.so.6:__strcpy_sse2) redirected to 0x484ee60 (strcpy)
--1765-- REDIR: 0x5100940 (libc.so.6:__strncpy_sse2) redirected to 0x484f1e0 (__strncpy_sse2)
--1765-- REDIR: 0x51049e0 (libc.so.6:__strcasecmp_sse2) redirected to 0x484f560 (strcasecmp)
--1765-- REDIR: 0x51138d0 (libc.so.6:__mempcpy_sse2_unaligned) redirected to 0x4853440 (mempcpy)
--1765-- REDIR: 0x5103c30 (libc.so.6:__rawmemchr_sse2) redirected to 0x4853360 (rawmemchr)
--1765-- REDIR: 0x51136a0 (libc.so.6:__strcspn_sse2) redirected to 0x4853c70 (strcspn)
==1765== Thread 2:
==1765== Conditional jump or move depends on uninitialised value(s)
==1765==    at 0x1508C6: do_log_run (log.c:532)
==1765==    by 0x150E3E: _log_open (log.c:166)
==1765==    by 0x150910: do_log_run (log.c:550)
==1765==    by 0x151B52: log_commit_entries (log.c:588)
==1765==    by 0x12F486: log_commit_thread (client.c:1060)
==1765==    by 0x14E6C0: _start_routine (thread.c:768)
==1765==    by 0x50E3B42: start_thread (pthread_create.c:442)
==1765==    by 0x5174BB3: clone (clone.S:100)
==1765== 
==1765== Thread 1:
==1765== Invalid write of size 8
==1765==    at 0x150ECD: create_log_entry (log.c:656)
==1765==    by 0x151FF9: log_write (log.c:741)
==1765==    by 0x12FF75: worker_start (client.c:956)
==1765==    by 0x12FF75: workers_adjust (client.c:1021)
==1765==    by 0x121516: slave_startup (slave.c:1261)
==1765==    by 0x121516: _slave_thread (slave.c:1272)
==1765==    by 0x121516: slave_initialize (slave.c:256)
==1765==    by 0x11609D: server_process (main.c:237)
==1765==    by 0x110262: main (main.c:436)
==1765==  Address 0x816e6d0 is 0 bytes inside a block of size 48 free'd
==1765==    at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==1765==    by 0x150B37: _log_close_internal.part.0 (log.c:432)
==1765==    by 0x150A32: _log_close_internal (log.c:411)
==1765==    by 0x150A32: do_log_run (log.c:573)
==1765==    by 0x151B52: log_commit_entries (log.c:588)
==1765==    by 0x12F486: log_commit_thread (client.c:1060)
==1765==    by 0x14E6C0: _start_routine (thread.c:768)
==1765==    by 0x50E3B42: start_thread (pthread_create.c:442)
==1765==    by 0x5174BB3: clone (clone.S:100)
==1765==  Block was alloc'd at
==1765==    at 0x484DA83: calloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==1765==    by 0x150E70: create_log_entry (log.c:633)
==1765==    by 0x151FF9: log_write (log.c:741)
==1765==    by 0x12F2F8: log_commit_thread (client.c:1041)
==1765==    by 0x14E6C0: _start_routine (thread.c:768)
==1765==    by 0x50E3B42: start_thread (pthread_create.c:442)
==1765==    by 0x5174BB3: clone (clone.S:100)
==1765== 
--1765-- REDIR: 0x5109b70 (libc.so.6:__strnlen_sse2) redirected to 0x484ecb0 (strnlen)
==1765== 
==1765== HEAP SUMMARY:
==1765==     in use at exit: 77,260 bytes in 1,458 blocks
==1765==   total heap usage: 34,954 allocs, 33,496 frees, 5,243,657 bytes allocated
==1765== 
==1765== Searching for pointers to 1,458 not-freed blocks
==1765== Checked 514,368 bytes
==1765== 
==1765== LEAK SUMMARY:
==1765==    definitely lost: 48 bytes in 1 blocks
==1765==    indirectly lost: 70,058 bytes in 1,191 blocks
==1765==      possibly lost: 0 bytes in 0 blocks
==1765==    still reachable: 7,154 bytes in 266 blocks
==1765==         suppressed: 0 bytes in 0 blocks
==1765== Rerun with --leak-check=full to see details of leaked memory
==1765== 
==1765== Use --track-origins=yes to see where uninitialised values come from
==1765== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 0 from 0)
==1765== 
==1765== 1 errors in context 1 of 2:
==1765== Invalid write of size 8
==1765==    at 0x150ECD: create_log_entry (log.c:656)
==1765==    by 0x151FF9: log_write (log.c:741)
==1765==    by 0x12FF75: worker_start (client.c:956)
==1765==    by 0x12FF75: workers_adjust (client.c:1021)
==1765==    by 0x121516: slave_startup (slave.c:1261)
==1765==    by 0x121516: _slave_thread (slave.c:1272)
==1765==    by 0x121516: slave_initialize (slave.c:256)
==1765==    by 0x11609D: server_process (main.c:237)
==1765==    by 0x110262: main (main.c:436)
==1765==  Address 0x816e6d0 is 0 bytes inside a block of size 48 free'd
==1765==    at 0x484B27F: free (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==1765==    by 0x150B37: _log_close_internal.part.0 (log.c:432)
==1765==    by 0x150A32: _log_close_internal (log.c:411)
==1765==    by 0x150A32: do_log_run (log.c:573)
==1765==    by 0x151B52: log_commit_entries (log.c:588)
==1765==    by 0x12F486: log_commit_thread (client.c:1060)
==1765==    by 0x14E6C0: _start_routine (thread.c:768)
==1765==    by 0x50E3B42: start_thread (pthread_create.c:442)
==1765==    by 0x5174BB3: clone (clone.S:100)
==1765==  Block was alloc'd at
==1765==    at 0x484DA83: calloc (in /usr/libexec/valgrind/vgpreload_memcheck-amd64-linux.so)
==1765==    by 0x150E70: create_log_entry (log.c:633)
==1765==    by 0x151FF9: log_write (log.c:741)
==1765==    by 0x12F2F8: log_commit_thread (client.c:1041)
==1765==    by 0x14E6C0: _start_routine (thread.c:768)
==1765==    by 0x50E3B42: start_thread (pthread_create.c:442)
==1765==    by 0x5174BB3: clone (clone.S:100)
==1765== 
==1765== 
==1765== 1 errors in context 2 of 2:
==1765== Thread 2:
==1765== Conditional jump or move depends on uninitialised value(s)
==1765==    at 0x1508C6: do_log_run (log.c:532)
==1765==    by 0x150E3E: _log_open (log.c:166)
==1765==    by 0x150910: do_log_run (log.c:550)
==1765==    by 0x151B52: log_commit_entries (log.c:588)
==1765==    by 0x12F486: log_commit_thread (client.c:1060)
==1765==    by 0x14E6C0: _start_routine (thread.c:768)
==1765==    by 0x50E3B42: start_thread (pthread_create.c:442)
==1765==    by 0x5174BB3: clone (clone.S:100)
==1765== 
==1765== ERROR SUMMARY: 2 errors from 2 contexts (suppressed: 0 from 0)
Moonbase59 commented 1 year ago

Off-topic @BusterNeece: You might want to look into the default fallbacks. My AAC stream gets a fallback file of /error.mp3 although you provide almost any fallback file type needed. Just noted while looking at the icecast.xml.

gunsar commented 1 year ago

i had the same problem on azuracast doker version Rolling Release #fd48a6a (2023-04-20 10:33 but after i changed Set as Default Mount Point to use is mount point with autodj settings and added files for fallback. then after restart docker and restart vps back to normal. immediately play station runs normally. for azuracast ansible there is no problem with the latest icacast-kh update

karlheyes commented 1 year ago

I think I have resolved at least one issue in the log aspect which was causing corruption. This was showing in the stack traces from these reports. This is now on the master tree.

karl

Moonbase59 commented 1 year ago

Thanks, @karlheyes , for the fast reaction & debugging hints. We’re testing right now, using commit https://github.com/karlheyes/icecast-kh/commit/f4084d99c5456ce73f6d46a7b071d189611bcc77. First try was a success but I will do a few restarts later on to (hopefully) verify stability.

Moonbase59 commented 1 year ago

FYI: 10 out of 10 restarts a success, guess you caught it, @karlheyes.

BusterNeece commented 1 year ago

Looks like we're in good shape here. Our users have reported that the recent commits fixed things up, so we shipped a new stable point release on our end to make sure users could avoid the crashes, even if they were intermittent. Since that stable release, we've had no new reports of any instability.

We'll keep up-to-date with changes on the main branch in our own Rolling Release branch. We'll also use the techniques we learned about here to provide better debug information for future issue reporting. Thank you for the quick turnaround!