svn-1236 crash on NSLU2

[richo132]

Ron,
Don’t know whether you’re still working on the memory leak issue.
Is there bug tracking number ?
Anyway my NSLU2 still consistently crashes after playing for about an hour. Attached logfile output shows the issue.

Also there is still a problem when scanning the iTunes.xml file for some songs with special chars – is there an open ticket on this ?

Cheers & keep up the good work,
Alan.

2006-06-16 18:39:29: Starting with debuglevel 1
2006-06-16 18:39:29: Starting rendezvous daemon
2006-06-16 18:39:29: Starting signal handler
2006-06-16 18:39:29: Initializing database
2006-06-16 18:41:44: Starting web server from /opt/share/mt-daapd/admin-root on port 3689
2006-06-16 18:41:44: Registering rendezvous names
2006-06-16 18:41:46: Scanned 9650 songs in 135 seconds
2006-06-16 18:41:46: Rescanning database
2006-06-16 18:50:52: Session 0: Streaming file ’02 Fortune plango vulnera.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 18:53:38: Session 0: Streaming file ’25 Fortune, Empress of the World_ 25.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 18:56:20: Session 0: Streaming file ’01 Kiss Me.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 18:59:47: Session 0: Streaming file ‘1-05 Forever And For Always.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 19:04:36: Session 0: Streaming file ’09 If I Could Start Today Again.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 19:07:30: Session 0: Streaming file ’08 White Witch.mp3′ to 192.168.0.250 (offset 0)
2006-06-16 19:10:51: Session 0: Streaming file ’03 Temptation Relation.mp3′ to 192.168.0.250 (offset 0)
2006-06-16 19:13:58: Session 0: Streaming file ’03 Tears Of Pearls.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 19:17:44: Session 0: Streaming file ’04 I Want You.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 19:21:33: Session 0: Streaming file ’01 Affirmation.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 19:26:29: Session 0: Streaming file ’01 Affirmation.mp3′ to 192.168.0.250 (offset 0)
2006-06-16 19:31:39: Session 0: Streaming file ’05 Crash and Burn.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 19:36:20: Session 0: Streaming file ’07 The Animal Song.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 19:41:22: Session 0: Streaming file ’01 Building A Mystery.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 19:45:31: Session 0: Streaming file ’01 Building A Mystery.mp3′ to 192.168.0.250 (offset 0)
2006-06-16 19:49:37: Session 0: Streaming file ’03 Sweet Surrender.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 19:53:43: Session 0: Streaming file ’04 Adia.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 20:34:35: Starting with debuglevel 1
2006-06-16 20:34:35: Starting rendezvous daemon
2006-06-16 20:34:35: Starting signal handler
2006-06-16 20:34:35: Initializing database
2006-06-16 20:36:50: Starting web server from /opt/share/mt-daapd/admin-root on port 3689
2006-06-16 20:36:50: Registering rendezvous names
2006-06-16 20:36:52: Scanned 9650 songs in 135 seconds
2006-06-16 20:36:52: Rescanning database
2006-06-16 20:43:44: Scanning /share/hdd/data/HDD_1_1_1/public/iTunes Music/iTunes Music Library.xml
2006-06-16 21:21:44: Session 0: Streaming file ’05 Wo bist du.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 21:21:58: Session 0: Streaming file ’05 Wo bist du.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 21:21:59: Session 0: Streaming file ’05 Wo bist du.m4a’ to 192.168.0.250 (offset 275529)
2006-06-16 21:25:43: Session 0: Streaming file ’07 Zerstoren.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 21:31:10: Session 0: Streaming file ’08 Hilf mir.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 21:36:04: Session 0: Streaming file ’02 Mein Teil.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 21:40:31: Session 0: Streaming file ’04 Keine Lust.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 21:44:29: Session 0: Streaming file ’01 Science Fiction, Double Feature.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 21:49:08: Session 0: Streaming file ’04 Time Warp.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 21:54:03: Session 0: Streaming file ’08 Whatever Happened To Saturday Nig.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 21:57:59: Session 0: Streaming file ’04 What’s The Frequency, Kenneth_.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 22:02:05: Session 0: Streaming file ’04 Everybody Hurts.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 22:07:20: Session 0: Streaming file ’10 Man On The Moon.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 22:12:32: Session 0: Streaming file ’02 My Happiness.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 22:17:06: Session 0: Streaming file ’08 Every You Every Me.mp3′ to 192.168.0.250 (offset 0)
2006-06-16 22:20:57: Session 0: Streaming file ’19 Science Fiction, Double Feature (.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 22:23:02: Session 0: Streaming file ‘1-05 Pure Morning.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 22:27:03: Rendezvous socket closed (daap server crashed?) Aborting.
2006-06-16 22:27:03: Aborting
2006-06-16 22:30:14: Starting with debuglevel 1
2006-06-16 22:30:14: Starting rendezvous daemon
2006-06-16 22:30:14: Starting signal handler
2006-06-16 22:30:14: Initializing database
2006-06-16 22:32:30: Starting web server from /opt/share/mt-daapd/admin-root on port 3689
2006-06-16 22:32:30: Registering rendezvous names
2006-06-16 22:32:32: Scanned 9650 songs in 136 seconds
2006-06-16 22:32:32: Rescanning database
2006-06-16 22:35:47: Session 0: Streaming file ‘1-07 Every You Every Me.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 22:37:02: Scanning /share/hdd/data/HDD_1_1_1/public/iTunes Music/iTunes Music Library.xml
2006-06-16 22:39:27: Session 0: Streaming file ’01 Leaving on a Jet Plane.m4a’ to 192.168.0.250 (offset 0)
2006-06-16 22:42:53: Session 0: Streaming file ’07 Puff (The Magic Dragon).m4a’ to 192.168.0.250 (offset 0)

[fizze]

well, debuglevel 1 isnt very verbosive 😉

you running unslung 6.8 ….?

[richo132]

fizze, thanks for your response.
Firmware Version: V2.3R63-uNSLUng-6.8-beta
I’ll run the log again with higher debug level.
However, as my issues have been previously reported I was checking on the status of the fixes.
Cheers.

[rpedde]

@richo132 wrote:

fizze, thanks for your response.
Firmware Version: V2.3R63-uNSLUng-6.8-beta
I’ll run the log again with higher debug level.
However, as my issues have been previously reported I was checking on the status of the fixes.
Cheers.

When I ran a stress test on my mac, I saw what looked like large memory leaks, but of course I don’t have valgrind on my mac, so I ran it on a gentoo box.

Couldn’t find a single substantial memory leak. Plus, with those all being m4a and mp3 files, it’s not the transcoding part or anything, so I’m kind of at a loss.

This rsp or daap?

As far as the iTunes xml thing, that’s going to be post-1.0. The fix is going to be hideous.

[richo132]

I’m running mt-daapd on the NSLU2 and connecting from iTunes on WinXP.
I have re-started mt-daapd with -d9 and will post some pieces of that.
If/when the crash occurs. The log file is very large – 30Mb to complete the database scan. Plus another 12Mb after playing for 3/4hr.

[rpedde]

@richo132 wrote:

I’m running mt-daapd on the NSLU2 and connecting from iTunes on WinXP.
I have re-started mt-daapd with -d9 and will post some pieces of that.
If/when the crash occurs. The log file is very large – 30Mb to complete the database scan. Plus another 12Mb after playing for 3/4hr.

Rather than post it, can you send it to me (zipped, please!) at ron at pedde.com?

Probably nothing of interest there, since I think it just gets oom killed.

Might be worth watching memory when it happens — see if the memory keeps going up.

[richo132]

Ron,
Have zipped and emailed the log files to you.
Cheers.

[fizze]

btw, whats proc/meminfo say on your slug ?
Did you set up extra swap space?

[richo132]

fizze, thanks for your response.
/proc/meminfo:
total: used: free: shared: buffers: cached:
Mem: 31256576 28811264 2445312 0 3874816 16523264
Swap: 129892352 6479872 123412480
MemTotal: 30524 kB
MemFree: 2388 kB
MemShared: 0 kB
Buffers: 3784 kB
Cached: 15228 kB
SwapCached: 908 kB
Active: 4588 kB
Inactive: 16984 kB
HighTotal: 0 kB
HighFree: 0 kB
LowTotal: 30524 kB
LowFree: 2388 kB
SwapTotal: 126848 kB
SwapFree: 120520 kB

I don’t recall any reference to extra swap space in the how to’s that I followed to unsling the NSLU2 and install mt-daapd. Unless something was included in the unsling script, I haven’t set up any extra swap space.
Cheers.

[richo132]

I can add this info – perhaps it will help:
mt-daapd.log (-d1):
2006-06-17 18:09:50: Starting with debuglevel 1
2006-06-17 18:09:50: Starting rendezvous daemon
2006-06-17 18:09:50: Starting signal handler
2006-06-17 18:09:50: Initializing database
2006-06-17 18:12:07: Starting web server from /opt/share/mt-daapd/admin-root on port 3689
2006-06-17 18:12:07: Registering rendezvous names
2006-06-17 18:12:09: Scanned 9650 songs in 138 seconds
2006-06-17 18:12:09: Rescanning database
2006-06-17 18:15:10: Scanning /share/hdd/data/HDD_1_1_1/public/iTunes Music/iTunes Music Library.xml
2006-06-17 18:19:00: Session 0: Streaming file ‘2-21 Hang On Sloopy.m4a’ to 192.168.0.250 (offset 0)
2006-06-17 18:21:36: Session 0: Streaming file ’01 Cry.mp3′ to 192.168.0.250 (offset 0)
2006-06-17 18:25:40: Session 0: Streaming file ’13 Little People.m4a’ to 192.168.0.250 (offset 0)
2006-06-17 18:29:17: Session 0: Streaming file ’07 Friday I’m In Love.m4a’ to 192.168.0.250 (offset 0)
2006-06-17 18:32:54: Session 0: Streaming file ’07 Cold.m4a’ to 192.168.0.250 (offset 0)
2006-06-17 18:37:17: Session 0: Streaming file ‘1-14 Friday I’m In Love.mp3’ to 192.168.0.250 (offset 0)
2006-06-17 18:40:56: Session 0: Streaming file ’11 The Night That Never End.mp3′ to 192.168.0.250 (offset 0)
2006-06-17 18:46:29: Session 0: Streaming file ’04 The Chariot.m4a’ to 192.168.0.250 (offset 0)
2006-06-17 18:52:28: Session 0: Streaming file ’03 HeartBeat.m4a’ to 192.168.0.250 (offset 0)
2006-06-17 18:56:11: Session 0: Streaming file ’06 Please Sister.m4a’ to 192.168.0.250 (offset 0)
2006-06-17 19:00:41: Session 0: Streaming file ’02 Been It.m4a’ to 192.168.0.250 (offset 0)
2006-06-17 19:04:56: Session 0: Streaming file ’02 Been It.mp3′ to 192.168.0.250 (offset 0)
2006-06-17 19:09:07: Session 0: Streaming file ’03 Take It Away.m4a’ to 192.168.0.250 (offset 0)
2006-06-17 19:14:01: Session 0: Streaming file ’01 They Will Kill Us All (Without Me.m4a’ to 192.168.0.250 (offset 0)
2006-06-17 19:17:50: Session 0: Streaming file ’11 Yesterday.mp3′ to 192.168.0.250 (offset 0)
2006-06-17 19:19:52: Session 0: Streaming file ’27 The Long and Winding Road.mp3′ to 192.168.0.250 (offset 0)
2006-06-17 19:23:31: Session 0: Streaming file ’01 Chic N’ Stu.m4a’ to 192.168.0.250 (offset 0)
2006-06-17 19:25:52: Session 0: Streaming file ’12 The Wild One.mp3′ to 192.168.0.250 (offset 0)
…CRASH

Crude monitoring of free memory in parallel to the above log:
(- its interesting to note how the available swap file space drops
down to <40000 at the time the server crashed.)

# date
Sat Jun 17 18:30:27 CST 2006
# free
total used free shared buffers
Mem: 30524 28996 1528 0 668
Swap: 126848 26060 100788
Total: 157372 55056 102316
# date
Sat Jun 17 18:30:41 CST 2006
# free
total used free shared buffers
Mem: 30524 29492 1032 0 732
Swap: 126848 26384 100464
Total: 157372 55876 101496
# date
Sat Jun 17 18:31:53 CST 2006
# free
total used free shared buffers
Mem: 30524 29652 872 0 632
Swap: 126848 27676 99172
Total: 157372 57328 100044
# date
Sat Jun 17 18:33:01 CST 2006
# free
total used free shared buffers
Mem: 30524 27892 2632 0 460
Swap: 126848 29268 97580
Total: 157372 57160 100212
# date
Sat Jun 17 18:37:25 CST 2006
# free
total used free shared buffers
Mem: 30524 27932 2592 0 572
Swap: 126848 34252 92596
Total: 157372 62184 95188
# date
Sat Jun 17 18:46:34 CST 2006
# free
total used free shared buffers
Mem: 30524 29844 680 0 392
Swap: 126848 45092 81756
Total: 157372 74936 82436
# date
Sat Jun 17 18:52:59 CST 2006
# free
total used free shared buffers
Mem: 30524 28644 1880 0 540
Swap: 126848 51980 74868
Total: 157372 80624 76748
# date
Sat Jun 17 18:56:34 CST 2006
# free
total used free shared buffers
Mem: 30524 29768 756 0 484
Swap: 126848 56612 70236
Total: 157372 86380 70992
# date
Sat Jun 17 19:00:53 CST 2006
# free
total used free shared buffers
Mem: 30524 29764 760 0 460
Swap: 126848 59508 67340
Total: 157372 89272 68100
# date
Sat Jun 17 19:16:26 CST 2006
# free
total used free shared buffers
Mem: 30524 29936 588 0 344
Swap: 126848 77160 49688
Total: 157372 107096 50276
# free
total used free shared buffers
Mem: 30524 29248 1276 0 1072
Swap: 126848 87460 39388
Total: 157372 116708 40664
# date
Sat Jun 17 19:28:20 CST 2006
# free
total used free shared buffers
Mem: 30524 29436 1088 0 1108
Swap: 126848 87460 39388
Total: 157372 116896 40476
#

[Author]

Posts