Icecast Streaming Media Server Forum Index Icecast Streaming Media Server
Icecast is a Xiph Foundation Project
 
 FAQFAQ   SearchSearch   MemberlistMemberlist   UsergroupsUsergroups   RegisterRegister 
 ProfileProfile   Log in to check your private messagesLog in to check your private messages   Log inLog in 

Segfault error 4

 
Post new topic   Reply to topic    Icecast Streaming Media Server Forum Index -> Icecast Server
View previous topic :: View next topic  
Author Message
Murrawhip



Joined: 21 Dec 2010
Posts: 58

PostPosted: Fri Jul 06, 2012 2:48 pm    Post subject: Segfault error 4 Reply with quote

Ubuntu
2.3.3-kh1

All of a sudden today 7 hours ago Icecast crashed.
There was nothing in Icecast's log about it.
It had never happened in the last 6 months or so of using icecast. I figured probably just bad luck, restarted it, and it's happened twice in the last 30 minutes.
I searched through /var/log and in /var/log/messages I found:
Quote:


Jul 6 00:51:01 srv1 kernel: [18246346.726777] icecast[13206]: segfault at 30 ip 0000000000424a48 sp 00007fd4392bbcb0 error 4 in icecast[400000+44000]
Jul 6 07:25:05 srv1 kernel: [18269990.986457] icecast[6440]: segfault at 12 ip 0000000000424a30 sp 00007f3da052fcb0 error 4 in icecast[400000+44000]
Jul 6 07:29:35 srv1 kernel: [18270260.972788] icecast[6823]: segfault at 12 ip 0000000000424a30 sp 00007f8a90d1acb0 error 4 in icecast[400000+44000]


Google leads me to believe I'm supposed to run Icecast with some kind of debugger and wait for the problem to happen again? How do I do that?

I've now rebooted the machine to see if that fixes it. It's fine for now, but I really want to try and prevent it from happening again.

P.S. Just crashed again after not too long:
Quote:

Jul 6 07:44:24 srv1 kernel: [ 692.640670] icecast[2228]: segfault at 12 ip 0000000000424a30 sp 00007f208b0a8cb0 error 4 in icecast[400000+44000]



P.P.S:
I used objdump --syms on Icecast to see if it's compiled with debugging symbols - Looks like it is. So do I just run Icecast under gdb like this? http://www.unknownroad.com/rtfm/gdbtut/gdbuse.html

P.P.P.S:
So I ran icecast under gdb.
It crashed after 15 minutes or so with this:
Quote:

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffff7fda700 (LWP 7440)]
send_iceblock_to_client (client=0xb97100) at format_mp3.c:555
555 if (refbuf->associated != client_mpg->associated)


Is that the only information I'm supposed to retrieve with gdb?
Back to top
View user's profile Send private message Visit poster's website
karlH
Code Warrior
Code Warrior


Joined: 13 Jun 2005
Posts: 5476
Location: UK

PostPosted: Fri Jul 06, 2012 9:31 pm    Post subject: Reply with quote

Most likely a bug from the recent rwlock merge. That particular function looks like it's still using the reference counts. I'll drop those operations now, as it could lead to bad pointers. This is a master feeding a slave relay of a similar version icecast.

This and another fix for restarting relays will mean a new release required.


karl.
Back to top
View user's profile Send private message Send e-mail Visit poster's website
Murrawhip



Joined: 21 Dec 2010
Posts: 58

PostPosted: Sat Jul 07, 2012 5:46 am    Post subject: Reply with quote

Okay sweet, thanks for looking into it. I was worried it was my system being screwy.
Back to top
View user's profile Send private message Visit poster's website
Murrawhip



Joined: 21 Dec 2010
Posts: 58

PostPosted: Tue Jan 29, 2013 3:57 pm    Post subject: Reply with quote

I was running KH3 up until today, when it started crashing via segfault every 5-40 minutes.
It had been running for months just fine until today. No software/hardware changes that I know of.

I upgraded to the latest github release and was receiving the same errors (I didn't have time to gdb, as it's a live system).

I downgraded back to KH3 and ran through gdb.

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x7ffff7fd5700 (LWP 18313)]
send_iceblock_to_client (client=0x7fffe40027c0) at format_mp3.c:562
562 if (refbuf->associated != client_mpg->associated)

(gdb) backtrace
#0 send_iceblock_to_client (client=0x7fffe40027c0) at format_mp3.c:562
#1 write_mpeg_buf_to_client (client=0x7fffe40027c0) at format_mp3.c:602
#2 0x0000000000415b7e in send_listener (client=0x7fffe40027c0, source=0x7fffec00eef0) at source.c:1078
#3 send_to_listener (client=0x7fffe40027c0) at source.c:953
#4 0x0000000000419e35 in worker (arg=0x692070) at client.c:561
#5 0x0000000000431c94 in _start_routine (arg=0x692130) at thread.c:673
#6 0x00007ffff6b3ee9a in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#7 0x00007ffff686bcbd in clone () from /lib/x86_64-linux-gnu/libc.so.6
#8 0x0000000000000000 in ?? ()


Anything I can do to get this resolved?

[Edit]: I've ruled out bad RAM.
[Edit2]: It crashed while on DEBUG. It's a server with ~25 streams and a few hundred listeners, so it's pretty chatty. This is the log entries from the last second:

Code:
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKPM" outgoing_kbitrate (259)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKPM" incoming_bitrate (128000)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKPM" total_bytes_read (69718934)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKPM" total_bytes_sent (102054912)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKPM" total_mbytes_sent (97)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKPM" queue_size (524121)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKPM" connected (4358)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_sent (7230331)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_read (1308124)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIRX" outgoing_kbitrate (1368)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIRX" incoming_bitrate (64168)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIRX" total_bytes_read (41146826)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIRX" total_bytes_sent (620530688)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIRX" total_mbytes_sent (591)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIRX" queue_size (524120)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIRX" connected (5143)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_sent (7231081)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_read (1308163)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIQC" outgoing_kbitrate (896)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIQC" incoming_bitrate (128112)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIQC" total_bytes_read (82287803)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIQC" total_bytes_sent (454090752)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIQC" total_mbytes_sent (433)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIQC" queue_size (524121)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CIQC" connected (5143)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_sent (7231638)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_read (1308241)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFNA" outgoing_kbitrate (598)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFNA" incoming_bitrate (96408)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFNA" total_bytes_read (61806297)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFNA" total_bytes_sent (296432640)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFNA" total_mbytes_sent (282)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFNA" queue_size (524121)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFNA" connected (5148)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_sent (7232018)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_read (1308302)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFPW" outgoing_kbitrate (88)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFPW" incoming_bitrate (139288)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFPW" total_bytes_read (89635107)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFPW" total_bytes_sent (24519680)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFPW" total_mbytes_sent (23)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFPW" queue_size (524121)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CFPW" connected (5148)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_sent (7232083)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_read (1308388)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKCQ" outgoing_kbitrate (474)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKCQ" incoming_bitrate (64000)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKCQ" total_bytes_read (41146518)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKCQ" total_bytes_sent (220707840)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKCQ" total_mbytes_sent (210)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKCQ" queue_size (524120)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "/CKCQ" connected (5143)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_sent (7232385)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" stream_kbytes_read (1308428)
[2013-01-29  12:52:29] WARN source/source_read Nothing received on /CFNI for 3 seconds
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" banned_IPs (0)
[2013-01-29  12:52:29] DBUG stats/modify_node_event update "global" outgoing_kbitrate (13968)
Back to top
View user's profile Send private message Visit poster's website
Murrawhip



Joined: 21 Dec 2010
Posts: 58

PostPosted: Wed Jan 30, 2013 7:30 am    Post subject: Reply with quote

I upgraded to the latest git release again, as I noticed you made a change in format_mp3.c

Code:
Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffff7fd5700 (LWP 16204)]
0x00007ffff67ae425 in raise () from /lib/x86_64-linux-gnu/libc.so.6


Edit:
I forgot to do a backtrace, so here's one:
Code:

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffff7fd5700 (LWP 18164)]
0x00007ffff67ae425 in raise () from /lib/x86_64-linux-gnu/libc.so.6
(gdb) backtrace
#0  0x00007ffff67ae425 in raise () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007ffff67b1b8b in abort () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x0000000000411fa0 in source_queue_advance (client=0x7fffe40047d0) at source.c:693
#3  0x0000000000415ed6 in send_listener (client=0x7fffe40047d0, source=0x7fffec10a250) at source.c:1078
#4  send_to_listener (client=0x7fffe40047d0) at source.c:946
#5  0x000000000041a455 in worker (arg=0x693070) at client.c:562
#6  0x00000000004328b4 in _start_routine (arg=0x693130) at thread.c:672
#7  0x00007ffff6b3ee9a in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#8  0x00007ffff686bcbd in clone () from /lib/x86_64-linux-gnu/libc.so.6
#9  0x0000000000000000 in ?? ()
Back to top
View user's profile Send private message Visit poster's website
karlH
Code Warrior
Code Warrior


Joined: 13 Jun 2005
Posts: 5476
Location: UK

PostPosted: Wed Jan 30, 2013 11:31 am    Post subject: Reply with quote

the abort is being triggered because of the buffer referenced is incorrect. What is not clear yet is how that came about. I suspect it's a lagging listener tripping this based on the lag values I've seen so far, but the more information I get the better. Any details about the stream in question?

karl.
Back to top
View user's profile Send private message Send e-mail Visit poster's website
Murrawhip



Joined: 21 Dec 2010
Posts: 58

PostPosted: Wed Jan 30, 2013 11:36 am    Post subject: Reply with quote

I'm not sure how to determine which stream is causing it.

Is there any other information out of gdb I could get that might help? I'm not particularly experienced in it.


I would say that this version from github is having the issue more often than kh3.

Github version crashes:
30/01/2013 01:59:12 AM
30/01/2013 02:06:38 AM
30/01/2013 02:10:38 AM
30/01/2013 02:20:49 AM
30/01/2013 02:33:20 AM
30/01/2013 02:41:50 AM
30/01/2013 02:43:01 AM
30/01/2013 02:50:21 AM
30/01/2013 02:54:46 AM
30/01/2013 03:05:07 AM
30/01/2013 03:17:53 AM

kh3 crashes:
29/01/2013 07:50:21 AM
29/01/2013 08:13:43 AM
29/01/2013 10:38:52 AM
29/01/2013 10:44:57 AM
29/01/2013 10:50:22 AM
29/01/2013 11:26:40 AM
29/01/2013 12:53:01 PM
29/01/2013 01:48:50 PM
29/01/2013 02:07:12 PM
29/01/2013 02:55:37 PM


Edit:
This is the entry in access.log immediately before the last crash:
removedIP - - [30/Jan/2013:04:03:05 -0800] "GET /CKQR HTTP/1.1" 200 3359507 "-" "Lavf52.111.0" 262

And the crash before that:
removedIP - - [30/Jan/2013:04:08:32 -0800] "GET /CJCD HTTP/1.1" 200 45260 "-" "NSPlayer/11.0.5721.5275 WMFSDK/11.0" 0

Doesn't look too relevant.
Back to top
View user's profile Send private message Visit poster's website
karlH
Code Warrior
Code Warrior


Joined: 13 Jun 2005
Posts: 5476
Location: UK

PostPosted: Wed Jan 30, 2013 1:20 pm    Post subject: Reply with quote

in gdb, in this case, you can do 'up' twice and then do p source->mount to show the mountpoint.

I've reverted the previous patch, but I put in a trap for a possible 0 length buffer case.

karl.


Last edited by karlH on Wed Jan 30, 2013 1:23 pm; edited 1 time in total
Back to top
View user's profile Send private message Send e-mail Visit poster's website
Murrawhip



Joined: 21 Dec 2010
Posts: 58

PostPosted: Wed Jan 30, 2013 1:21 pm    Post subject: Reply with quote

Okay I'm running your new version under gdb. Will update when it crashes.
Back to top
View user's profile Send private message Visit poster's website
Murrawhip



Joined: 21 Dec 2010
Posts: 58

PostPosted: Wed Jan 30, 2013 1:35 pm    Post subject: Reply with quote

Code:

[Switching to Thread 0x7ffff7fd5700 (LWP 13300)]
0x00007ffff67ae425 in raise () from /lib/x86_64-linux-gnu/libc.so.6

(gdb) backtrace
#0  0x00007ffff67ae425 in raise () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007ffff67b1b8b in abort () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x0000000000411fa0 in source_queue_advance (client=0x7fffe4005aa0) at source.c:693
#3  0x0000000000415ed6 in send_listener (client=0x7fffe4005aa0, source=0x7fffec9bc4a0) at source.c:1078
#4  send_to_listener (client=0x7fffe4005aa0) at source.c:946
#5  0x000000000041a455 in worker (arg=0x692f10) at client.c:562
#6  0x00000000004328b4 in _start_routine (arg=0x692fd0) at thread.c:672
#7  0x00007ffff6b3ee9a in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#8  0x00007ffff686bcbd in clone () from /lib/x86_64-linux-gnu/libc.so.6
#9  0x0000000000000000 in ?? ()

mount:
$1 = 0x7fffec010660 "/CHNV"


I'll wait for it to crash again to determine if it's happening on the one mountpoint.
Back to top
View user's profile Send private message Visit poster's website
Murrawhip



Joined: 21 Dec 2010
Posts: 58

PostPosted: Wed Jan 30, 2013 1:50 pm    Post subject: Reply with quote

Code:
Program received signal SIGABRT, Aborted.
[Switching to Thread 0x7ffff7fd5700 (LWP 14389)]
0x00007ffff67ae425 in raise () from /lib/x86_64-linux-gnu/libc.so.6
(gdb) backtrace
#0  0x00007ffff67ae425 in raise () from /lib/x86_64-linux-gnu/libc.so.6
#1  0x00007ffff67b1b8b in abort () from /lib/x86_64-linux-gnu/libc.so.6
#2  0x0000000000411fa0 in source_queue_advance (client=0x7fffe4003c70) at source.c:693
#3  0x0000000000415ed6 in send_listener (client=0x7fffe4003c70, source=0x7fffec0f9cb0) at source.c:1078
#4  send_to_listener (client=0x7fffe4003c70) at source.c:946
#5  0x000000000041a455 in worker (arg=0x692f10) at client.c:562
#6  0x00000000004328b4 in _start_routine (arg=0x692fd0) at thread.c:672
#7  0x00007ffff6b3ee9a in start_thread () from /lib/x86_64-linux-gnu/libpthread.so.0
#8  0x00007ffff686bcbd in clone () from /lib/x86_64-linux-gnu/libc.so.6
#9  0x0000000000000000 in ?? ()


(gdb) p source->mount
$1 = 0x7fffec0f85a0 "/CJSU"

Different mountpoint. Hmm.
Back to top
View user's profile Send private message Visit poster's website
karlH
Code Warrior
Code Warrior


Joined: 13 Jun 2005
Posts: 5476
Location: UK

PostPosted: Wed Jan 30, 2013 2:06 pm    Post subject: Reply with quote

it seems that you can reproduce it easily, do you have a procedure that I could duplicate?

karl.
Back to top
View user's profile Send private message Send e-mail Visit poster's website
Murrawhip



Joined: 21 Dec 2010
Posts: 58

PostPosted: Wed Jan 30, 2013 2:14 pm    Post subject: Reply with quote

I'm not really doing anything special, that I know of.
I just wait for 10-30 minutes and it happens.
I've just emailed you a link to my icecast.xml, and my stats.xsl. There's barely any listeners right now and it's still happening.
Back to top
View user's profile Send private message Visit poster's website
karlH
Code Warrior
Code Warrior


Joined: 13 Jun 2005
Posts: 5476
Location: UK

PostPosted: Thu Jan 31, 2013 3:05 pm    Post subject: Reply with quote

When you can try it, can you test out the latest updates.

karl.
Back to top
View user's profile Send private message Send e-mail Visit poster's website
Display posts from previous:   
Post new topic   Reply to topic    Icecast Streaming Media Server Forum Index -> Icecast Server All times are GMT
Page 1 of 1

 
Jump to:  
You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum
You cannot vote in polls in this forum


Powered by phpBB © 2001, 2002 phpBB Group
subRebel style by ktauber