svn-1488 feedback

[rpedde]

@Ted Harper wrote:

I didn’t recompile at all, just installed the distributed .ipk (and didn’t allow it to (re-)create the .conf file either, so that would have been identical to what was working with the previous nightly).

k. 1489 is cooking right now. Should be up on nightlies site in a half-hour or so.

— Ron

[S80_UK]

@rpedde wrote:

Did either of you compile with –enable-mem-debug?

No – I didn’t either. As Ted, I just installed the ipk.

For reasons unknown I could not get 1463 to go back (have been trying to with the –force-reinstall or –force-downgrade options etc, but no luck. (that’s a newbie problem I think).

Will try svn-1489 and see what happens. Many thanks.

[CCRDude]

Need some more details about the crashes in svn-1488? I had about four in eight hours yesterday, most with about two dozen mt-daapd processes open even after client access has been totally crashed. Here’s the last output from the log file before the crash (with default -d 2):

2007-01-17 21:52:21 (00028004): Session 0: Streaming file ‘Bia?e ?ciany.mp3’ to 192.168.1.229 (offset 0)
2007-01-17 21:52:39 (00030005): Session 0: Streaming file ‘Moje z?o.mp3’ to 192.168.1.229 (offset 0)
2007-01-17 21:52:40 (00028004): Write error: Broken pipe
2007-01-17 21:52:49 (00038004): Session 0: Streaming file ‘Najtrudniej.mp3’ to 192.168.1.229 (offset 0)
2007-01-17 21:52:50 (00030005): Write error: Broken pipe
2007-01-17 21:52:52 (00040005): Session 0: Streaming file ‘Mimo wszystko.mp3’ to 192.168.1.229 (offset 0)
2007-01-17 21:52:53 (00038004): Write error: Broken pipe
2007-01-17 21:52:56 (00048004): Session 0: Streaming file ‘On tu jest.mp3’ to 192.168.1.229 (offset 0)
2007-01-17 21:52:56 (00040005): Write error: Broken pipe
2007-01-17 21:52:57 (00050005): Session 0: Streaming file ‘Kiedy powiem sobie do??.mp3’ to 192.168.1.229 (offset 0)
2007-01-17 21:52:59 (00048004): Write error: Broken pipe

Here are the last lines from the crash before that:

2007-01-17 17:24:05 (0009c006): Thread 35: Entering ws_returnerror (401: Unauthorized)
2007-01-17 17:24:06 (000a0006): Write error: Broken pipe
2007-01-17 17:24:07 (000a8006): Write error: Broken pipe
2007-01-17 17:24:57 (000ac003): Thread 39: could not read: No such file or directory
2007-01-17 17:26:27 (00100003): Session 0: Streaming file ‘Traum vom Tod II.mp3’ to 192.168.1.229 (offset 0)
2007-01-17 17:26:49 (00114004): Session 0: Streaming file ‘Der Vagabund.mp3’ to 192.168.1.12 (offset 0)
2007-01-17 17:26:54 (00114004): Write error: Connection reset by peer
2007-01-17 17:26:54 (0011c004): Session 0: Streaming file ‘Der Vagabund.mp3’ to 192.168.1.12 (offset 1808747)
2007-01-17 17:26:57 (0011c004): Write error: Connection reset by peer

I’m now running it with -d 9 instead.

Then it ran a few hours, and then, after the end of one track:

2007-01-18 01:05:56 (002a4009): Added *Date=Thu, 18 Jan 2007 00:05:56 GMT*
2007-01-18 01:05:56 (002a4009): Added *Connection=close*
2007-01-18 01:05:56 (002a4009): Added *Server=mt-daapd/svn-1488*
2007-01-18 01:05:56 (002a4009): Added *Content-Type=text/html*
2007-01-18 01:05:56 (002a4009): Added *Content-Language=en_us*
2007-01-18 01:05:56 (002a4009): Thread 165: Using non-default handler
2007-01-18 01:05:56 (002a4009): in main_auth
2007-01-18 01:05:56 (002a4009): Checking url /rsp/db/0
2007-01-18 01:05:56 (002a4009): Checking url /rsp/db/0
2007-01-18 01:05:56 (002a4009): Dispatching auth for /rsp/db/0 to plugin
2007-01-18 01:05:56 (002a4009): Checking url /rsp/db/0
2007-01-18 01:05:56 (002a4009): Checking url /rsp/db/0
2007-01-18 01:05:56 (002a4009): Dispatching /rsp/db/0 to rsp/svn-1488
2007-01-18 01:05:56 (002a4009): in main_handler
2007-01-18 01:05:56 (002a4009): Checking url /rsp/db/0
2007-01-18 01:05:56 (002a4009): Checking url /rsp/db/0
2007-01-18 01:05:56 (002a4009): Dispatching /rsp/db/0 to plugin
2007-01-18 01:05:56 (002a4009): Checking url /rsp/db/0
2007-01-18 01:05:56 (002a4009): Checking url /rsp/db/0
2007-01-18 01:05:56 (002a4009): Dispatching /rsp/db/0 to rsp/svn-1488
2007-01-18 01:05:56 (002a4009): Getting uri…
2007-01-18 01:05:56 (002a4009): Mallocing privinfo…
2007-01-18 01:05:56 (002a4009): Tokenizing url
2007-01-18 01:05:56 (002a4009): Found 5 elements
2007-01-18 01:05:56 (002a4009): Checking reponse 0
2007-01-18 01:05:56 (002a4009): Checking reponse 1
2007-01-18 01:05:56 (002a4009): Checking reponse 2
2007-01-18 01:05:56 (002a4009): Found it! Index: 2
2007-01-18 01:05:56 (002a4009): Returning token 2002
2007-01-18 01:05:56 (002a4009): Entering sp_parse_phrase
2007-01-18 01:05:56 (002a4009): Entering sp_parse_oexpr
2007-01-18 01:05:56 (002a4009): Entering sp_parse_aexpr
2007-01-18 01:05:56 (002a4009): Entering sp_parse_expr
2007-01-18 01:05:56 (002a4009): Entering sp_parse_criterion
2007-01-18 01:05:56 (002a4009): Entering sp_parse_int_criterion
2007-01-18 01:05:56 (002a4009): Returning token 000f
2007-01-18 01:05:56 (002a4009): Returning token 00fd
2007-01-18 01:05:56 (002a4009): Exiting sp_parse_int_criterion (success)
2007-01-18 01:05:56 (002a4009): Exiting sp_parse_criterion (success)
2007-01-18 01:05:56 (002a4009): Exiting sp_parse_expr (success)
2007-01-18 01:05:56 (002a4009): Exiting sp_parse_aexpr (success)
2007-01-18 01:05:56 (002a4009): Exiting sp_parse_oexpr (success)
2007-01-18 01:05:56 (002a4009): Exiting sp_parse_phrase (success)

And while I cannot reach it through the SB or iTunes any more, there are way too much instances running:

jukebox:~# ps -Al | grep mt-daapd
5 S 65534 1844 1 0 76 0 – 1610 select ? 00:00:00 mt-daapd
5 S 65534 1845 1 4 75 0 – 59424 hrtime ? 00:08:35 mt-daapd
1 S 65534 1846 1845 0 76 0 – 59424 sys_po ? 00:00:00 mt-daapd
1 S 65534 1855 1846 0 76 0 – 59424 inet_c ? 00:00:00 mt-daapd
1 R 65534 2823 1846 56 85 0 – 59424 – ? 00:22:24 mt-daapd
1 S 65534 2868 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2871 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2875 1846 0 77 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2877 1846 0 76 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2878 1846 0 76 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2888 1846 0 77 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2892 1846 0 76 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2896 1846 0 77 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2897 1846 0 76 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2898 1846 0 76 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2901 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2902 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2903 1846 0 77 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2904 1846 0 77 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2909 1846 0 77 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2910 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2911 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2912 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2914 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2929 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2930 1846 0 77 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2933 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2934 1846 0 77 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2940 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 2943 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd
1 S 65534 3061 1846 0 78 0 – 59424 rt_sig ? 00:00:00 mt-daapd

I’m now back to svn-1450 for the day (had that still compiled on the disk, so I could just do a make install, I can try 1488 or 1489 with –enable-mem-debug this evening probably if necessary.

edit: a way to crash svn-1488 seems to be to browse with the Soundbridge while an iTunes is connecting to the database. svn-1450 does only fail on the Soundbridge then, but svn-1488 crashed on that yesterday once as well.

[S80_UK]

@S80_UK wrote:

Will try svn-1489 and see what happens. Many thanks.

OK – so I got svn-1489 to install. I got only a minor error (I assume due to my failed attempts to get back to 1463) which was this…

Collected errors:
Multiple packages (mt-daapd and mt-daapd) providing same name marked HOLD or PREFER. Using latest.

But it now works!!!! 😀 It’s early days yet, but scanning and everything seems OK

Many thanks for the quick fix!

Les.

Setup: NSLU2 (266MHz), Unslung 6.8 (to stick), SoundBridge M1000 (wireless), Linksys WAG354G-UK (ADSL router)

[CCRDude]

Oh sorry, I missed that 1489 was there between things 😉

Trying to connect from both SB and iTunes at the same time still fails on the Soundbridge (Connection to server failed, nothing in -d 2 log), but works afterwards, so no crashing issue.

Going to have a full office day of playing back iTunes and SB now to see how it’ll do 😉

[rpedde]

@CCRDude wrote:

Oh sorry, I missed that 1489 was there between things 😉

Trying to connect from both SB and iTunes at the same time still fails on the Soundbridge (Connection to server failed, nothing in -d 2 log), but works afterwards, so no crashing issue.

Going to have a full office day of playing back iTunes and SB now to see how it’ll do 😉

Oosh… still looks like some signal problems. I think I forgot to handle SIGCLD. D’oh! No child reapage. I’ll fix that tonight. Once that’s done, I wonder how the signal stuff will work. I’ve had strange signal problems with some platforms, and I hope moving signal handling to the process leader might help on some pthreads implementations.

— Ron

[CCRDude]

Those reports from the long post were all still 1488…. 1489 behaved quite nicely so far… 5 open processes with the SB currently streaming looks about expected. tcpdump has about three dozen of these entries listed though:

tcp        0      0 jukebox:daap            machinename.my.intranet:1854 TIME_WAIT

And that’s with this named machine haven been off for 12 hours and just turned on again, no iTunes running here yet, and no background iTunesHelper either.
Only one tcpdump line for the Soundbridge I just started, which looks better.

[Author]

Posts