A hang in send_ogg_headers()
I've recently had the following hang of icecast2 server. Not sure if it's the first time, but it's pretty rare anyway, so i can't reliably reproduce, but this time i managed to debug a little.
I'm running on ubuntu 12.04 vps with default package (icecast2-2.3.2-9ubuntu1), didn't try to pull the latest svn version yet.
$ tail /var/log/icecast2
...
[2014-02-16 08:27:40] DBUG client/client_send_bytes Client connection died
[2014-02-16 08:27:40] DBUG client/client_send_bytes Client connection died
[2014-02-16 08:27:40] DBUG client/client_send_bytes Client connection died
[2014-02-16 08:27:40] DBUG client/client_send_bytes Client connection died
[2014-02-16 08:27:40] DBUG client/client_send_bytes Client connection died
[2014-02-16 08:27:40] DBUG client/client_send_bytes Client connection died
[2014-02-16 08:27:40] DBUG client/client_send_bytes Client connection died
[2014-02-16 08:27:40] DBUG client/client_send_bytes Client connection died
[2014-02-16 08:27:40] DBUG client/client_send_bytes Client connection died
[2014-02-16 08:27:40] DBUG client/client_send_bytes Client connection died
...
$ strace -p `pidof icecast2` -f 2>&1 | grep send
...
[pid 26113] send(14, 0x5ff8e559, 2406954578, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e558, 2406954579, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e557, 2406954580, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e556, 2406954581, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e555, 2406954582, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e554, 2406954583, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e553, 2406954584, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e552, 2406954585, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e551, 2406954586, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e550, 2406954587, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e54f, 2406954588, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e54e, 2406954589, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e54d, 2406954590, 0) = -1 EPIPE (Broken pipe)
[pid 26113] send(14, 0x5ff8e54c, 2406954591, 0) = -1 EPIPE (Broken pipe)
...
You may notice how buffer address decreases by 1 and buffer length increases by 1 on every line; no other send()
calls happen, so i could easily backtrace them:
$ gdb -p `pidof icecast`
...
Breakpoint 1, 0xb7461e40 in send () from /lib/i386-linux-gnu/tls/i686/nosegneg/libpthread.so.0
(gdb) bt
#0 0xb7461e40 in send () from /lib/i386-linux-gnu/tls/i686/nosegneg/libpthread.so.0
#1 0x08067c40 in sock_write_bytes (sock=14, buff=0x5f08fe9d, len=2422676750) at sock.c:360
#2 0x0804f9aa in connection_send (con=0x9748ac8, buf=0x5f08fe9d, len=2422676750) at connection.c:303
#3 0x08058d20 in client_send_bytes (client=0x9740a38, buf=0x5f08fe9d, len=2422676750) at client.c:202
#4 0x0805e6c2 in send_ogg_headers (headers=0xb666e848, client=0x9740a38) at format_ogg.c:500
#5 write_buf_to_client (client=0x9740a38) at format_ogg.c:534
#6 0x08054f57 in send_to_listener (deletion_expected=0, client=0x9740a38, source=0xb647c7d8) at source.c:544
#7 source_main (source=0xb647c7d8) at source.c:716
#8 0x0805564f in source_client_thread (arg=0xb647c7d8) at source.c:1225
#9 0x08068b2f in _start_routine (arg=0xb6674970) at thread.c:655
#10 0xb745ad4c in start_thread () from /lib/i386-linux-gnu/tls/i686/nosegneg/libpthread.so.0
#11 0xb7398ace in clone () from /lib/i386-linux-gnu/tls/i686/nosegneg/libc.so.6
...