You are here: Home » Topic » 20051114 linux crash …

20051114 linux crash …

This topic contains 10 replies, has 3 voices, and was last updated by  rpedde 11 years, 10 months ago.

Viewing 11 posts - 1 through 11 (of 11 total)
  • Author
    Posts
  • #130

    eddieb
    Participant

    2005-11-15 20:07:29: Entering config_handler
    2005-11-15 20:07:29: Entering config_set_status
    2005-11-15 20:07:29: Exiting config_set_status
    2005-11-15 20:07:29: Updating Connection from keep-alive to close
    2005-11-15 20:07:29: Thread 99: Preparing to serve /usr/share/mt-daapd/admin-root/mt-daapd.png
    2005-11-15 20:07:29: Emitting reponse header Content-Language: en_us
    2005-11-15 20:07:29: Emitting reponse header Content-Type: text/html
    2005-11-15 20:07:29: Emitting reponse header Server: mt-daapd/cvs-20051114
    2005-11-15 20:07:29: Emitting reponse header Connection: close
    2005-11-15 20:07:29: Emitting reponse header Date: Tue, 15 Nov 2005 19:07:29 GMT
    2005-11-15 20:07:29: Thread 99: Served successfully
    2005-11-15 20:07:29: Entering config_set_status
    2005-11-15 20:07:29: Exiting config_set_status
    2005-11-15 20:07:29: Thread 99: Terminating
    2005-11-15 20:07:29: Thread 99: Freeing request headers
    2005-11-15 20:07:29: Thread 99: Freeing response headers
    2005-11-15 20:07:29: Thread 99: Freeing request vars
    2005-11-15 20:07:29: Thread 99: Closing fd
    2005-11-15 20:07:29: With thread 99 exiting, 0 are still running
    Rendezvous socket closed (daap server crashed?) Aborting.
    Aborting
    2005-11-15 20:07:35: Processing rendezvous message
    2005-11-15 20:07:35: Rendezvous socket closed (daap server crashed?) Aborting.
    2005-11-15 20:07:35: Aborting

    (within 5 minutes …)

    #3810

    rpedde
    Participant

    Yeah, I’m getting that, too. I thought I had it, but apparently not. Still a race out there somewhere. That’s what I’m going to try and get fixed tonight.

    — Ron

    #3811

    saintdev

    Well using the avahi patch works fine. Switching to howl gives me the following:

    Starting rendezvous services
    Starting polling thread
    Entering runloop
    Waiting for data
    Registering rendezvous names
    Received a message from daap server
    Registering _daap._tcp.XXX’s Music (3689)
    Received a message from daap server
    Registering _http._tcp.XXX’s Music (3689)
    Publish reply: stopped
    Publish reply: name collision

    ^C

    Stopping rendezvous daemon
    Received a message from daap server
    Stopping mDNS
    Received a message from daap server
    Rendezvous socket closed (daap server crashed?) Aborting.
    Aborting

    Not sure if this helps. It looks like for some reason it trys to register the name twice.

    #3812

    rpedde
    Participant

    There must be another machine on the network with that name registered (XXX’s Music). Perhaps you have it set up as a static entry in your howl config.

    #3813

    saintdev

    Well that’s the only problem I seem to be getting. Nothing in the howl config, avahi is stopped, and mDNSBrowse _daap._tcp shows nothing until I start up mt-daapd.

    Here’s more info on my setup.

    Finally!

    Updating Connection from keep-alive to close
    Cannot resolve /usr/share/mt-daapd/admin-root//favicon.ico
    Thread 14: Entering ws_returnerror (404: Not found)
    Updating Connection from close to close
    Emitting reponse header Content-Language: en_us

    Program received signal SIGPIPE, Broken pipe.
    [Switching to Thread 1098918240 (LWP 22986)]
    0x00002aaaaabcbf0f in __write_nocancel () from /lib/tls/libpthread.so.0

    (gdb) bt
    #0 0x00002aaaaabcbf0f in __write_nocancel () from /lib/tls/libpthread.so.0
    #1 0x000000000040a5ae in r_write (fd=10, buf=0x417ff7e0, size=25)
    at restart.c:140
    #2 0x00000000004067e4 in ws_writefd (pwsc=0x54e080, fmt=0x41ebc2 “%s: %srn”)
    at webserver.c:991
    #3 0x0000000000406848 in ws_emitheaders (pwsc=0x54e080) at webserver.c:548
    #4 0x00000000004068f2 in ws_returnerror (pwsc=0x54e080, error=404,
    description=0x41ecc9 “Not found”) at webserver.c:1019
    #5 0x000000000040975b in config_handler (pwsc=0x54e080) at configfile.c:706
    #6 0x00000000004071a3 in ws_dispatcher (arg=0xa) at webserver.c:958
    #7 0x00002aaaaabc70fa in start_thread () from /lib/tls/libpthread.so.0
    #8 0x00002aaaab7b1a73 in clone () from /lib/tls/libc.so.6
    #9 0x0000000000000000 in ?? ()
    #10 0x0000000000000000 in ?? ()
    #11 0x0000000000000000 in ?? ()
    #12 0x0000000000000000 in ?? ()
    #13 0x0000000000000000 in ?? ()
    #14 0x0000000000000000 in ?? ()
    #15 0x0000000000000000 in ?? ()
    #16 0x0000000000000000 in ?? ()
    #17 0x0000000000000000 in ?? ()
    #18 0x0000000000000000 in ?? ()
    #19 0x0000000000000000 in ?? ()

    ./configure –prefix=/usr –host=x86_64-pc-linux-gnu –mandir=/usr/share/man –infodir=/usr/share/info –datadir=/usr/share –sysconfdir=/etc –localstatedir=/var/lib –disable-avahi –enable-oggvorbis –enable-sqlite –enable-flac –enable-debug –enable-debug-memory –enable-howl –with-howl-libs=/usr/lib –with-howl-includes=/usr/include/howl/ –libdir=/usr/lib64 –build=x86_64-pc-linux-gnu

    http://saintdevelopment.com/mt-daapd.conf

    Post edited by: saintdev, at: 2005/11/16 03:41

    #3814

    rpedde
    Participant

    That gdb catch is probably normal though — I’m guessing that the client side closed the connection before mt-daapd did, and that’s why the sigpipe.

    sigpipe should be ignored, though, so except for the fact that it’s running under gdb, it would keep running.

    I’ve been stressing this thing by beating on it while playing music, while attached to a gdb session, and I’m picking some stuff up, but not the thread status race, which is the breakage everyone is probably seeing, I think.

    I’m going to keep banging away on it until I find everything. 🙂

    #3815

    saintdev

    how about this?

    Breakpoint 1, dispatch_output_end (pwsc=0x8e, pqi=0x56f270) at dispatch.c:521
    521 int dispatch_output_end(WS_CONNINFO *pwsc, DBQUERYINFO *pqi) {
    (gdb) step
    522 OUTPUT_INFO *poi = pqi->output_info;
    (gdb)
    521 int dispatch_output_end(WS_CONNINFO *pwsc, DBQUERYINFO *pqi) {
    (gdb)
    524 if((poi) && (poi->xml_output) && (poi->stack_height)) {
    (gdb)
    528 config_set_status(pwsc,pqi->session_id,NULL);
    (gdb)
    config_set_status (pwsc=0x57d170, session=7728064, fmt=0x75ebc0 “”)
    at configfile.c:1241
    1241 void config_set_status(WS_CONNINFO *pwsc, int session, char *fmt, …) {
    (gdb)
    1247 DPRINTF(E_DBG,L_CONF,”Entering config_set_statusn”);
    (gdb) finish
    Run till exit from #0 config_set_status (pwsc=0x57d170, session=0, fmt=0x0)
    at configfile.c:1247
    Entering config_set_status
    Exiting config_set_status
    dispatch_output_end (pwsc=0x57d170, pqi=0x75ebc0) at dispatch.c:529
    529 free(poi);
    (gdb) step
    err_free (file=0x75ebc0 “”, line=5755248, ptr=0x75ebc0) at err.c:359
    359 void err_free(char *file, int line, void *ptr) {
    (gdb)
    362 if(err_lock_mutex())
    (gdb)
    err_lock_mutex () at err.c:237
    237 int err_lock_mutex(void) {
    (gdb)
    240 if((err=pthread_mutex_lock(&err_mutex))) {
    (gdb)
    245 return 0;
    (gdb)
    240 if((err=pthread_mutex_lock(&err_mutex))) {
    (gdb)
    246 }
    (gdb)
    err_free (file=0x421be1 “dispatch.c”, line=529, ptr=0xa6fd90) at err.c:366
    366 current=last->next;
    (gdb)
    365 last=&err_leak;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb)
    370 current=current->next;
    (gdb)
    369 last=current;
    (gdb) finish
    Run till exit from #0 err_free (file=0x421be1 “dispatch.c”, line=529,
    ptr=0xa6fd90) at err.c:369

    Stops at that point. It seems it gets stuck in the while loop in err_free.

    GAH! maybe not, unable to reproduce this again, but it’s time to go to bed :/

    Post edited by: saintdev, at: 2005/11/16 07:23

    #3816

    Mike
    Participant

    I dunno how much help this is, but here’s the last 80 lines of my log file when run at -d 9 using 20051114. I hope that there’s some info in there for you that you can use.

    2005-11-16 03:42:16: Received Response from 192.168.1.103 addressed to 224.0.0.251 on 0808BB98 TTL 255 with 0 Questions, 8 Answers, 0 Authorities, 1 Additional
    2005-11-16 03:42:16: select(6, 1963459.834960)
    2005-11-16 03:42:31: SocketDataReady got a packet from 192.168.1.103 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:42:31: Received Query from 192.168.1.103 :5353 to 224.0.0.251 :5353 on 0x0808BB98 with 2 Questions, 3 Answers, 0 Authorities, 0 Additionals
    2005-11-16 03:42:31: AddRecordToResponseList: _daap._tcp.local. (PTR) already in list
    2005-11-16 03:42:31: AddRecordToResponseList: The Mirror._daap._tcp.local. (SRV) already in list
    2005-11-16 03:42:31: AddRecordToResponseList: The Mirror._daap._tcp.local. (TXT) already in list
    2005-11-16 03:42:31: AddRecordToResponseList: mirror.local. (Addr) already in list
    2005-11-16 03:42:31: select(6, 0.094726)
    2005-11-16 03:42:31: select(6, 0.001953)
    2005-11-16 03:42:31: mDNS_Execute
    2005-11-16 03:42:31: select(6, 1963444.684570)
    2005-11-16 03:42:32: SocketDataReady got a packet from 192.168.1.103 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:42:32: Received Response from 192.168.1.103 addressed to 224.0.0.251 on 0808BB98 TTL 255 with 0 Questions, 8 Answers, 0 Authorities, 1 Additional
    2005-11-16 03:42:32: select(6, 1963443.834960)
    2005-11-16 03:42:46: SocketDataReady got a packet from 192.168.1.99 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:42:46: Received Response from 192.168.1.99 addressed to 224.0.0.251 on 0808BB98 TTL 255 with 0 Questions, 4 Answers, 0 Authorities, 0 Additionals
    2005-11-16 03:42:46: select(6, 1963430.081054)
    2005-11-16 03:43:03: SocketDataReady got a packet from 192.168.1.103 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:43:03: Received Query from 192.168.1.103 :5353 to 224.0.0.251 :5353 on 0x0808BB98 with 2 Questions, 3 Answers, 0 Authorities, 0 Additionals
    2005-11-16 03:43:03: AddRecordToResponseList: _daap._tcp.local. (PTR) already in list
    2005-11-16 03:43:03: AddRecordToResponseList: The Mirror._daap._tcp.local. (SRV) already in list
    2005-11-16 03:43:03: AddRecordToResponseList: The Mirror._daap._tcp.local. (TXT) already in list
    2005-11-16 03:43:03: AddRecordToResponseList: mirror.local. (Addr) already in list
    2005-11-16 03:43:03: select(6, 0.109375)
    2005-11-16 03:43:03: mDNS_Execute
    2005-11-16 03:43:03: select(6, 1963412.666992)
    2005-11-16 03:43:04: SocketDataReady got a packet from 192.168.1.103 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:43:04: Received Response from 192.168.1.103 addressed to 224.0.0.251 on 0808BB98 TTL 255 with 0 Questions, 8 Answers, 0 Authorities, 1 Additional
    2005-11-16 03:43:04: select(6, 1963411.833007)
    2005-11-16 03:44:07: SocketDataReady got a packet from 192.168.1.103 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:44:07: Received Query from 192.168.1.103 :5353 to 224.0.0.251 :5353 on 0x0808BB98 with 2 Questions, 3 Answers, 0 Authorities, 0 Additionals
    2005-11-16 03:44:07: AddRecordToResponseList: _daap._tcp.local. (PTR) already in list
    2005-11-16 03:44:07: AddRecordToResponseList: The Mirror._daap._tcp.local. (SRV) already in list
    2005-11-16 03:44:07: AddRecordToResponseList: The Mirror._daap._tcp.local. (TXT) already in list
    2005-11-16 03:44:07: AddRecordToResponseList: mirror.local. (Addr) already in list
    2005-11-16 03:44:07: select(6, 0.051757)
    2005-11-16 03:44:07: select(6, 0.002929)
    2005-11-16 03:44:07: mDNS_Execute
    2005-11-16 03:44:07: select(6, 1963348.722656)
    2005-11-16 03:44:08: SocketDataReady got a packet from 192.168.1.103 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:44:08: Received Response from 192.168.1.103 addressed to 224.0.0.251 on 0808BB98 TTL 255 with 0 Questions, 6 Answers, 0 Authorities, 0 Additionals
    2005-11-16 03:44:08: select(6, 1963347.830078)
    2005-11-16 03:46:15: SocketDataReady got a packet from 192.168.1.103 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:46:15: Received Query from 192.168.1.103 :5353 to 224.0.0.251 :5353 on 0x0808BB98 with 2 Questions, 3 Answers, 0 Authorities, 0 Additionals
    2005-11-16 03:46:15: AddRecordToResponseList: _daap._tcp.local. (PTR) already in list
    2005-11-16 03:46:15: AddRecordToResponseList: The Mirror._daap._tcp.local. (SRV) already in list
    2005-11-16 03:46:15: AddRecordToResponseList: The Mirror._daap._tcp.local. (TXT) already in list
    2005-11-16 03:46:15: AddRecordToResponseList: mirror.local. (Addr) already in list
    2005-11-16 03:46:15: select(6, 0.058593)
    2005-11-16 03:46:15: mDNS_Execute
    2005-11-16 03:46:15: select(6, 1963220.710937)
    2005-11-16 03:46:16: SocketDataReady got a packet from 192.168.1.103 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:46:16: Received Response from 192.168.1.103 addressed to 224.0.0.251 on 0808BB98 TTL 255 with 0 Questions, 6 Answers, 0 Authorities, 0 Additionals
    2005-11-16 03:46:16: select(6, 1963219.825195)
    2005-11-16 03:50:31: SocketDataReady got a packet from 192.168.1.103 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:50:31: Received Query from 192.168.1.103 :5353 to 224.0.0.251 :5353 on 0x0808BB98 with 2 Questions, 3 Answers, 0 Authorities, 0 Additionals
    2005-11-16 03:50:31: AddRecordToResponseList: _daap._tcp.local. (PTR) already in list
    2005-11-16 03:50:31: AddRecordToResponseList: The Mirror._daap._tcp.local. (SRV) already in list
    2005-11-16 03:50:31: AddRecordToResponseList: The Mirror._daap._tcp.local. (TXT) already in list
    2005-11-16 03:50:31: AddRecordToResponseList: mirror.local. (Addr) already in list
    2005-11-16 03:50:31: select(6, 0.035156)
    2005-11-16 03:50:31: mDNS_Execute
    2005-11-16 03:50:31: select(6, 1962964.726562)
    2005-11-16 03:50:32: SocketDataReady got a packet from 192.168.1.103 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:50:32: Received Response from 192.168.1.103 addressed to 224.0.0.251 on 0808BB98 TTL 255 with 0 Questions, 6 Answers, 0 Authorities, 0 Additionals
    2005-11-16 03:50:32: select(6, 1962963.817382)
    2005-11-16 03:59:03: SocketDataReady got a packet from 192.168.1.103 to 224.0.0.251 on interface 192.168.1.98/eth0/2
    2005-11-16 03:59:03: Received Query from 192.168.1.103 :5353 to 224.0.0.251 :5353 on 0x0808BB98 with 2 Questions, 3 Answers, 0 Authorities, 0 Additionals
    2005-11-16 03:59:03: AddRecordToResponseList: _daap._tcp.local. (PTR) already in list
    2005-11-16 03:59:03: AddRecordToResponseList: The Mirror._daap._tcp.local. (SRV) already in list
    2005-11-16 03:59:03: AddRecordToResponseList: The Mirror._daap._tcp.local. (TXT) already in list
    2005-11-16 03:59:03: AddRecordToResponseList: mirror.local. (Addr) already in list
    2005-11-16 03:59:03: select(6, 0.023437)
    2005-11-16 03:59:03: select(6, 0.000976)
    2005-11-16 03:59:03: mDNS_Execute
    2005-11-16 03:59:03: select(6, 1962452.718750)
    2005-11-16 04:03:34: Processing rendezvous message
    2005-11-16 04:03:34: Rendezvous socket closed (daap server crashed?) Aborting.
    2005-11-16 04:03:34: Aborting

    It takes just over an hour for the daemon to crash, it seems. Everything is fine up ’till then.

    #3817

    rpedde
    Participant

    I ended up reproing by running five or six console windows banging the heck out of the web interface until it died.

    gdb was no real help trying to find what code path forgot to lock something. had to rely on printf debugging. woohoo.

    Found it eventually. Bad combination of typo and stupido. The stupido fell out pretty quick — the typo took longer. 🙂

    Fixed in 1116, though.

    — Ron

    #3818

    saintdev

    And I was just about to let you know that I got a result! Running about 12 wget loops I finally got a seg fault.


    Program received signal SIGSEGV, Segmentation fault.
    [Switching to Thread 1317128544 (LWP 30409)]
    ws_thread_enum_first (wsh=0x53b3d0, vpp=0x4e817ac8) at webserver.c:1583
    1583 pwsc = pconlist->pwsc;
    #3819

    rpedde
    Participant

    Gar!

    Messed up merging my “riddled with printf-debugging” fixes with the 1116 nightly. Should *really* be fixed in 1117.

    Only 6 people had downloaded the not-really-fixed 1116 before I fixed it.

    Dang it.

Viewing 11 posts - 1 through 11 (of 11 total)

You must be logged in to reply to this topic.