Server (svn-1082) crashes after 30mins or so

[richo132]

Hi,
I have installed Version svn-1082 on my slug.
120Gb WD HDD in an unbranded USB2 drive on port2
iTunes xml file is parsed and songs.db created ok
Music library has 9000+ songs
Windows iTunes clients connect and start playing ok
After 20 – 30 mins, the mt-daapd server crashes
This is unfortunately quite repeatable.
Any suggestions would be welcome.

Extract from daapd.log (3 PCs connected on this occasion) :
1970-01-01 09:31:23: Starting rendezvous daemon
1970-01-01 09:31:23: Starting signal handler
1970-01-01 09:31:23: Initializing database
2006-05-28 21:35:21: Starting web server from /opt/share/mt-daapd/admin-root on port 3689
2006-05-28 21:35:21: Registering rendezvous names
2006-05-28 21:35:22: Scanned 9349 songs in 1148817838 seconds
2006-05-28 21:35:22: Rescanning database
2006-05-28 21:35:22: Session 0: Streaming file ’05 People Like You.m4a’ to 192.168.0.243 (offset 0)
2006-05-28 21:35:22: Session 0: Streaming file ’03 USA Today.m4a’ to 192.168.0.248 (offset 0)
2006-05-28 21:39:23: Session 0: Streaming file ’08 Chains Of Misery.m4a’ to 192.168.0.250 (offset 0)
2006-05-28 21:43:04: Session 0: Streaming file ’09 The Apparition.m4a’ to 192.168.0.250 (offset 0)
2006-05-28 21:47:01: Session 0: Streaming file ’10 Judas Be My Guide.m4a’ to 192.168.0.250 (offset 0)
2006-05-28 21:48:47: Session 0: Streaming file ’01 Don’t Pay the Ferryman.m4a’ to 192.168.0.243 (offset 0)
2006-05-28 21:50:44: Session 0: Streaming file ’11 Weekend Warrior.m4a’ to 192.168.0.250 (offset 0)
2006-05-28 21:50:45: Session 0: Streaming file ’01 The Ecstasy Of Flight (I Love The.m4a’ to 192.168.0.248 (offset 0)
2006-05-28 21:53:00: Session 0: Streaming file ’01 The Ecstasy Of Flight (I Love The.m4a’ to 192.168.0.243 (offset 0)
2006-05-28 21:54:56: Session 0: Streaming file ’05 The Sound Of A Gun.m4a’ to 192.168.0.248 (offset 0)
2006-05-28 21:56:23: Session 0: Streaming file ’12 Fear Of The Dark.m4a’ to 192.168.0.250 (offset 0)
2006-05-28 21:57:14: Session 0: Streaming file ’05 The Sound Of A Gun.m4a’ to 192.168.0.243 (offset 0)
2006-05-28 22:01:21: Session 0: Streaming file ’10 Transmission Ends.m4a’ to 192.168.0.248 (offset 0)
2006-05-28 22:02:29: Session 0: Streaming file ’10 Transmission Ends.m4a’ to 192.168.0.243 (offset 0)
2006-05-28 22:05:46: Session 0: Streaming file ’01 Tailgunner.m4a’ to 192.168.0.250 (offset 0)
2006-05-28 22:07:30: Session 0: Streaming file ’01 Wicked Game.m4a’ to 192.168.0.248 (offset 0)
2006-05-28 22:10:50: Session 0: Streaming file ’01 Wicked Game.m4a’ to 192.168.0.243 (offset 0)
2006-05-28 22:10:51: Session 0: Streaming file ’02 Holy Smoke.m4a’ to 192.168.0.250 (offset 0)
2006-05-28 22:12:32: Session 0: Streaming file ’09 Don’t Get So Down On Yourself.m4a’ to 192.168.0.248 (offset 0)
2006-05-28 22:15:42: Session 0: Streaming file ’09 Don’t Get So Down On Yourself.m4a’ to 192.168.0.243 (offset 0)
2006-05-28 22:15:43: Session 0: Streaming file ’03 No Prayer For The Dying.m4a’ to 192.168.0.250 (offset 0)
2006-05-28 22:16:02: Session 0: Streaming file ’06 Things Go Wrong.m4a’ to 192.168.0.248 (offset 0)
2006-05-28 22:20:03: Session 0: Streaming file ’08 There She Goes.m4a’ to 192.168.0.248 (offset 0)
2006-05-28 22:20:04: Session 0: Streaming file ’04 Public Enema Number One.m4a’ to 192.168.0.250 (offset 0)
2006-05-28 22:20:04: Session 0: Streaming file ’06 Things Go Wrong.m4a’ to 192.168.0.243 (offset 0)
2006-05-28 22:22:58: Scanning /share/flash/data/public/iTunes Music/iTunes Music Library.xml
2006-05-28 22:23:01: Session 0: Streaming file ’08 There She Goes.m4a’ to 192.168.0.243 (offset 0)
2006-05-28 22:23:17: Session 0: Streaming file ’12 I Believe.m4a’ to 192.168.0.248 (offset 0)
2006-05-28 22:26:27: Session 0: Streaming file ’12 I Believe.m4a’ to 192.168.0.243 (offset 0)

Listing from “ps” command after crash:
# ps
PID TTY Uid Size State Command
1 root 1212 S /bin/init
2 root 0 S [keventd]
3 root 0 S [ksoftirqd_CPU0]
4 root 0 S [kswapd]
5 root 0 S [bdflush]
6 root 0 S [kupdated]
7 root 0 S [mtdblockd]
8 root 0 S [khubd]
9 root 0 S [jffs2_gcd_mtd4]
10 root 0 S [usb-storage-0]
11 root 0 S [scsi_eh_0]
13 root 0 S [sd-mc-thread]
27 root 0 S [kjournald]
50 root 0 D [ixp425_csr]
51 root 0 S [ixp425 ixp0]
54 ttyS0 root 1916 S /bin/sh
55 root 1936 S /sbin/syslogd -n
56 root 1924 S /sbin/klogd -n
147 root 0 S [kjournald]
308 root 2132 S /usr/sbin/thttpd -C /etc/thttpd.conf
332 root 6148 S /usr/sbin/smbd -D
334 root 6148 S /usr/sbin/smbd -D
335 root 4824 S /usr/sbin/nmbd -D
342 root 1272 S /bin/inetd
358 root 1952 S /usr/sbin/QuickSet
364 root 1904 S /usr/sbin/USB_Detect
365 root 1900 S /usr/sbin/USB_Detect
374 root 1884 S /usr/sbin/onetouch_detect
376 root 1884 S /usr/sbin/onetouch_detect
395 root 1928 S /usr/sbin/CheckResetButton
397 root 1196 S /usr/sbin/CheckPowerButton
399 root 1196 S /usr/sbin/do_umount
444 root 3188 S /opt/sbin/sshd
451 guest 3784 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
452 guest 84004 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
455 guest 84004 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
456 guest 84004 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
471 root 5936 S sshd: root@notty
473 root 1912 S sh -c /opt/libexec/sftp-server
474 root 3140 S /opt/libexec/sftp-server
538 guest 84004 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
554 root 1296 S /usr/sbin/crond
557 root 1296 S /usr/sbin/crond
575 root 6452 S /usr/sbin/smbd -D
576 guest 84004 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
579 guest 84004 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
580 guest 84004 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
610 guest 84004 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
611 guest 84004 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
612 guest 84004 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
613 guest 84004 S /opt/sbin/mt-daapd -c /opt/etc/mt-daapd/mt-
614 root 5796 S sshd: root@ttyp0
616 ttyp0 root 1920 S -sh
618 ttyp0 root 1984 R ps
#

Killing 451 and 452 was enough to kill all other mt-daapd threads
I could then restart.

[fizze]

manually change the init script so mt-daapd runs with -d9.
This gives more useful debugging messages and log output.

[rpedde]

@richo132 wrote:

Killing 451 and 452 was enough to kill all other mt-daapd threads
I could then restart.

Are you using the transcoding scripts? Or is everything m4a and mp3?

[richo132]

Thanks for responses.
No transcoding – all songs are m4a (90%) or mp3 (10%).
Will capture some logfile entries with -d9.

[richo132]

Right, here is last 53 lines of mt-daapd.log with debug -d9.
The whole file is over 14Mb or zips to 750Kb.
The server ran longer this time before crashing.
Maybe the -d9 debugging made a difference somehow.

1970-01-01 10:34:23: Thread 15: Connection type HTTP/1.1
: Connection: persist
1970-01-01 10:34:23: Thread 15: parsing GET args
1970-01-01 10:34:23: Thread 15: Entering ws_getgetvars (type=music&meta=dmap.itemkind,dmap.itemid,dmap.containeritemid&revision-number=4130&delta=4119)
1970-01-01 10:34:23: Thread 15: Adding arg type = music
1970-01-01 10:34:23: Added *type=music*
1970-01-01 10:34:23: Thread 15: Adding arg meta = dmap.itemkind,dmap.itemid,dmap.containeritemid
1970-01-01 10:34:23: Added *meta=dmap.itemkind,dmap.itemid,dmap.containeritemid*
1970-01-01 10:34:23: Thread 15: Adding arg revision-number = 4130
1970-01-01 10:34:23: Added *revision-number=4130*
1970-01-01 10:34:23: Thread 15: Adding arg delta = 4119
1970-01-01 10:34:23: Added *delta=4119*
1970-01-01 10:34:23: Thread 15: Done parsing GET/POST args!
1970-01-01 10:34:23: Thread 15: Original URI: /databases/1/containers/194/items
1970-01-01 10:34:23: Thread 15: Translated URI: /databases/1/containers/194/items
1970-01-01 10:34:23: Thread 15: Preparing to find handler
1970-01-01 10:34:23: Thread 15: URI Match!
1970-01-01 10:34:23: Thread 15: Time is 3863 seconds after epoch
1970-01-01 10:34:23: Thread 15: Setting time header
1970-01-01 10:34:23: Added *Date=Thu, 1 Jan 1970 01:04:23 GMT*
1970-01-01 10:34:23: Thread 15: Using non-default handler
1970-01-01 10:34:23: Added *Accept-Ranges=bytes*
1970-01-01 10:34:23: Added *DAAP-Server=mt-daapd/svn-1082*
1970-01-01 10:34:23: Added *Content-Type=application/x-dmap-tagged*
1970-01-01 10:34:23: Added *Cache-Control=no-cache*
1970-01-01 10:34:23: Added *Expires=-1*
1970-01-01 10:34:23: meta codes: 21
1970-01-01 10:34:23: Thread 23: Length of file (remaining) is 5419487
1970-01-01 10:34:23: Updating Content-Type from application/x-dmap-tagged to audio/m4a
1970-01-01 10:34:23: Added *Content-Length=5419487*
1970-01-01 10:34:23: Added *Connection=Close*
1970-01-01 10:34:23: Emitting reponse header Connection: Close
1970-01-01 10:34:23: Emitting reponse header Content-Length: 5419487
1970-01-01 10:34:23: Emitting reponse header Expires: -1
1970-01-01 10:34:23: Emitting reponse header Cache-Control: no-cache
1970-01-01 10:34:23: Emitting reponse header Content-Type: audio/m4a
1970-01-01 10:34:23: Emitting reponse header DAAP-Server: mt-daapd/svn-1082
1970-01-01 10:34:23: Emitting reponse header Accept-Ranges: bytes
1970-01-01 10:34:23: Emitting reponse header Date: Thu, 1 Jan 1970 01:04:20 GMT
1970-01-01 10:34:23: Entering config_set_status
1970-01-01 10:34:23: Exiting config_set_status
1970-01-01 10:34:23: Session 0: Streaming file ’01 Objection (Tango).m4a’ to 192.168.0.250 (offset 0)
1970-01-01 10:37:55: Finished streaming file to remote: 5419487 bytes
1970-01-01 10:38:01: Thread 24: Entering ws_dispatcher (Connection from 192.168.0.250)
1970-01-01 10:38:01: Thread 24: got request
1970-01-01 10:38:01: Request: GET daap://192.168.0.15:3689/databases/1/items/3493.m4a HTTP/1.1
1970-01-01 10:38:01: Thread 24: Read: Accept: */*
1970-01-01 10:38:01: Thread 24: Adding header *Accept=*/**
1970-01-01 10:38:01: Added *Accept=*/**
1970-01-01 10:38:01: Thread 24: Read: Cache-Control: no-cache
1970-01-01 10:38:01: Thread 24: Adding header *Cache-Control=no-cache*
1970-01-01 10:38:01: Added *Cache-Control=no-cache*
1970-01-01 10:38:01: Thread 24: Read: User-Agent: iTunes/6.0.4 (Windows; N)
1970-01-01 10:38:01: Thread 24: Adding header *User-Agent=iTunes/6.0.4 (Windows; N)*
1970-01-01 10:38:01: Added *User-Agent=iTunes/6.0.4 (Windows; N)*
1970-01-01 10:38:01: Thread 24: Read: Client-DAAP-Access-Index: 2
1970-01-01 10:38:01: Thread 24: Adding header *Client-DAAP-Access-Index=2*
1970-01-01 10:38:01: Added *Client-DAAP-Access-Index=2*
1970-01-01 10:38:01: Thread 24: Read: Client-DAAP-Validation: 301150BEB518C72C01DE26D35691DD39
1970-01-01 10:38:01: Thread 24: Adding header *Client-DAAP-Validation=301150BEB518C72C01DE26D35691DD39*
1970-01-01 10:38:01: Added *Client-DAAP-Validation=301150BEB518C72C01DE26D35691DD39*
1970-01-01 10:38:01: Thread 24: Read: Client-DAAP-Request-ID: 15
1970-01-01 10:38:01: Thread 24: Adding header *Client-DAAP-Request-ID=15*
1970-01-01 10:38:01: Added *Client-DAAP-Request-ID=15*
1970-01-01 10:38:01: Thread 24: Read: Connection: close
1970-01-01 10:38:01: Thread 24: Adding header *Connection=close*
1970-01-01 10:38:01: Added *Connection=close*
1970-01-01 10:38:01: Thread 24: Read:
1970-01-01 10:38:01: Thread 24: Headers parsed!
1970-01-01 10:38:01: Checking to see if connection matches close
1970-01-01 10:38:01: And it DOES!
1970-01-01 10:38:01: Thread 24: Connection type HTTP/1.1
: Connection: non-persist
1970-01-01 10:38:01: Thread 24: Original URI: daap://192.168.0.15:3689/databases/1/items/3493.m4a
1970-01-01 10:38:01: Thread 24: Translated URI: /databases/1/items/3493.m4a
1970-01-01 10:38:01: Thread 24: Preparing to find handler
1970-01-01 10:38:01: Thread 24: URI Match!
1970-01-01 10:38:01: Thread 24: Time is 4081 seconds after epoch
1970-01-01 10:38:01: Thread 24: Setting time header
1970-01-01 10:38:01: Added *Date=Thu, 1 Jan 1970 01:08:01 GMT*
1970-01-01 10:38:01: Thread 24: Using non-default handler
1970-01-01 10:38:01: Added *Accept-Ranges=bytes*
1970-01-01 10:38:01: Added *DAAP-Server=mt-daapd/svn-1082*
1970-01-01 10:38:01: Added *Content-Type=application/x-dmap-tagged*
1970-01-01 10:38:01: Added *Cache-Control=no-cache*
1970-01-01 10:38:01: Added *Expires=-1*
1970-01-01 10:40:43: SocketDataReady got a packet from 192.168.0.243 to 224.0.0.251 on interface 192.168.0.15/ixp0/2
1970-01-01 10:40:43: Received Query from 192.168.0.243 :5353 to 224.0.0.251 :5353 on 0x0005B1C0 with 2 Questions, 3 Answers, 0 Authorities, 0 Additionals
1970-01-01 10:40:43: AddRecordToResponseList: _daap._tcp.local. (PTR) already in list
1970-01-01 10:40:43: AddRecordToResponseList: sTunes._daap._tcp.local. (SRV) already in list
1970-01-01 10:40:43: AddRecordToResponseList: sTunes._daap._tcp.local. (TXT) already in list
1970-01-01 10:40:43: AddRecordToResponseList: Slug.local. (Addr) already in list
1970-01-01 10:40:43: select(6, 0.062500)
1970-01-01 10:40:43: mDNS_Execute
1970-01-01 10:40:43: select(6, 1961921.068359)

[Author]

Posts