Reply To: svn-1488 feedback

#8554
CCRDude
Participant

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.