Timout in Select

[Anonymous]

Hi,

Have the problem that my 1696 build on Suse 10.2 will run for ~45 min and then disappear from iTunes (7.6.2) and stop serving music.

Here is the level 9 log that I get from the system to the point where the first timeout in select statements start. Significant time can pass between the Timeout message and the actual failure to serve music.

Does anyone have an idea for how to resolve this problem ?

Added *Content-Type=text/html*
Added *Content-Language=en_us*
Thread 6: Using non-default handler
in main_auth
Checking url /databases/1/items/27.mp3
Checking url /databases/1/items/27.mp3
Dispatching auth for /databases/1/items/27.mp3 to plugin
Checking url /databases/1/items/27.mp3
Checking url /databases/1/items/27.mp3
Dispatching /databases/1/items/27.mp3 to daap/svn-1696
in main_handler
Checking url /databases/1/items/27.mp3
Checking url /databases/1/items/27.mp3
Dispatching /databases/1/items/27.mp3 to plugin
Checking url /databases/1/items/27.mp3
Checking url /databases/1/items/27.mp3
Dispatching /databases/1/items/27.mp3 to daap/svn-1696
Getting uri…
Mallocing privinfo…
Added *Accept-Ranges=bytes*
Added *DAAP-Server=firefly/svn-1696*
Updating Content-Type from text/html to application/x-dmap-tagged
Added *Cache-Control=no-cache*
Added *Expires=-1*
Tokenizing url
Found 17 elements
Checking reponse 0
Checking reponse 1
Checking reponse 2
Checking reponse 3
Checking reponse 4
Checking reponse 5
Checking reponse 6
Checking reponse 7
Checking reponse 8
Checking reponse 9
Found it! Index: 9
Executing: select * from songs where id=27
Creating new db handle
Opening file:///home/media/music/iTunes/Rhianna/Good+Girl+Gone+Bad/07++Rihanna+-+Say+It.mp3
Checking handler for file
opening /home/media/music/iTunes/Rhianna/Good Girl Gone Bad/07 Rihanna – Say It.mp3
Thread 6: Length of file (remaining): 6017119
Updating Content-Type from application/x-dmap-tagged to audio/mp3
Added *Content-Length=6017119*
Updating Connection from close to Close
Emitting reponse header Content-Length: 6017119
Emitting reponse header Expires: -1
Emitting reponse header Cache-Control: no-cache
Emitting reponse header DAAP-Server: firefly/svn-1696
Emitting reponse header Accept-Ranges: bytes
Emitting reponse header Content-Language: en_us
Emitting reponse header Content-Type: audio/mp3
Emitting reponse header Server: mt-daapd/svn-1696
Emitting reponse header Connection: Close
Emitting reponse header Date: Mon, 2 Jun 2008 22:37:33 GMT
Entering config_set_status
Exiting config_set_status
Session 0: Streaming file ’07 Rihanna – Say It.mp3′ to 192.168.0.209 (offset 0)
Finished streaming file to remote: 6017119 bytes
Entering config_set_status
Exiting config_set_status
Executing: update songs set play_count=play_count + 1, time_played=1212446496 where id=27
Rows: 1
Thread 6: Terminating
Thread 6: Freeing request headers
Thread 6: Freeing response headers
Thread 6: Freeing request vars
Thread 6: Closing fd
With thread 6 exiting, 1 are still running
Got listen socket 10
Thread 7:
Request: GET daap://192.168.0.15:3689/databases/1/items/28.mp3 HTTP/1.1
Thread 7: Read: Accept: */*
Thread 7: Adding header *Accept=*/**
Added *Accept=*/**
Thread 7: Read: Cache-Control: no-cache
Thread 7: Adding header *Cache-Control=no-cache*
Added *Cache-Control=no-cache*
Thread 7: Read: User-Agent: iTunes/7.6.2 (Windows; N)
Thread 7: Adding header *User-Agent=iTunes/7.6.2 (Windows; N)*
Added *User-Agent=iTunes/7.6.2 (Windows; N)*
Thread 7: Read: Client-DAAP-Access-Index: 2
Thread 7: Adding header *Client-DAAP-Access-Index=2*
Added *Client-DAAP-Access-Index=2*
Thread 7: Read: Client-DAAP-Validation: E6B8AFD6268B0430516587B249BAA01B
Thread 7: Adding header *Client-DAAP-Validation=E6B8AFD6268B0430516587B249BAA01B*
Added *Client-DAAP-Validation=E6B8AFD6268B0430516587B249BAA01B*
Thread 7: Read: Client-DAAP-Request-ID: 7
Thread 7: Adding header *Client-DAAP-Request-ID=7*
Added *Client-DAAP-Request-ID=7*
Thread 7: Read: x-audiocast-udpport: 57095
Thread 7: Adding header *x-audiocast-udpport=57095*
Added *x-audiocast-udpport=57095*
Thread 7: Read: icy-metadata: 1
Thread 7: Adding header *icy-metadata=1*
Added *icy-metadata=1*
Thread 7: Read: Connection: close
Thread 7: Adding header *Connection=close*
Added *Connection=close*
Thread 7: Read:
Thread 7: Headers parsed!
Checking to see if connection matches close
And it DOES!
Thread 7: Connection type HTTP/1.1
: Connection: non-persist
Thread 7: Original URI: daap://192.168.0.15:3689/databases/1/items/28.mp3
Thread 7: Translated URI: /databases/1/items/28.mp3
Thread 7: Preparing to find handler
Checking /databases/1/items/28.mp3 against handler for /
Thread 7: URI Match!
Thread 7: Time is 1212446504 seconds after epoch
Thread 7: Setting time header
Added *Date=Mon, 2 Jun 2008 22:41:44 GMT*
Added *Connection=close*
Added *Server=mt-daapd/svn-1696*
Added *Content-Type=text/html*
Added *Content-Language=en_us*
Thread 7: Using non-default handler
in main_auth
Checking url /databases/1/items/28.mp3
Checking url /databases/1/items/28.mp3
Dispatching auth for /databases/1/items/28.mp3 to plugin
Checking url /databases/1/items/28.mp3
Checking url /databases/1/items/28.mp3
Dispatching /databases/1/items/28.mp3 to daap/svn-1696
in main_handler
Checking url /databases/1/items/28.mp3
Checking url /databases/1/items/28.mp3
Dispatching /databases/1/items/28.mp3 to plugin
Checking url /databases/1/items/28.mp3
Checking url /databases/1/items/28.mp3
Dispatching /databases/1/items/28.mp3 to daap/svn-1696
Getting uri…
Mallocing privinfo…
Added *Accept-Ranges=bytes*
Added *DAAP-Server=firefly/svn-1696*
Updating Content-Type from text/html to application/x-dmap-tagged
Added *Cache-Control=no-cache*
Added *Expires=-1*
Tokenizing url
Found 17 elements
Checking reponse 0
Checking reponse 1
Checking reponse 2
Checking reponse 3
Checking reponse 4
Checking reponse 5
Checking reponse 6
Checking reponse 7
Checking reponse 8
Checking reponse 9
Found it! Index: 9
Executing: select * from songs where id=28
Creating new db handle
Opening file:///home/media/music/iTunes/Rhianna/Good+Girl+Gone+Bad/03++Rihanna+-+Don%27t+Stop+The+Music.mp3
Checking handler for file
opening /home/media/music/iTunes/Rhianna/Good Girl Gone Bad/03 Rihanna – Don’t Stop The Music.mp3
Thread 7: Length of file (remaining): 6409753
Updating Content-Type from application/x-dmap-tagged to audio/mp3
Added *Content-Length=6409753*
Updating Connection from close to Close
Emitting reponse header Content-Length: 6409753
Emitting reponse header Expires: -1
Emitting reponse header Cache-Control: no-cache
Emitting reponse header DAAP-Server: firefly/svn-1696
Emitting reponse header Accept-Ranges: bytes
Emitting reponse header Content-Language: en_us
Emitting reponse header Content-Type: audio/mp3
Emitting reponse header Server: mt-daapd/svn-1696
Emitting reponse header Connection: Close
Emitting reponse header Date: Mon, 2 Jun 2008 22:41:44 GMT
Entering config_set_status
Exiting config_set_status
Session 0: Streaming file ’03 Rihanna – Don’t Stop The Music.mp3′ to 192.168.0.209 (offset 0)
Finished streaming file to remote: 6409753 bytes
Entering config_set_status
Exiting config_set_status
Executing: update songs set play_count=play_count + 1, time_played=1212446763 where id=28
Rows: 1
Thread 7: Terminating
Thread 7: Freeing request headers
Thread 7: Freeing response headers
Thread 7: Freeing request vars
Thread 7: Closing fd
With thread 7 exiting, 1 are still running
Got listen socket 12
Thread 8:
Request: GET daap://192.168.0.15:3689/databases/1/items/29.mp3 HTTP/1.1
Thread 8: Read: Accept: */*
Thread 8: Adding header *Accept=*/**
Added *Accept=*/**
Thread 8: Read: Cache-Control: no-cache
Thread 8: Adding header *Cache-Control=no-cache*
Added *Cache-Control=no-cache*
Thread 8: Read: User-Agent: iTunes/7.6.2 (Windows; N)
Thread 8: Adding header *User-Agent=iTunes/7.6.2 (Windows; N)*
Added *User-Agent=iTunes/7.6.2 (Windows; N)*
Thread 8: Read: Client-DAAP-Access-Index: 2
Thread 8: Adding header *Client-DAAP-Access-Index=2*
Added *Client-DAAP-Access-Index=2*
Thread 8: Read: Client-DAAP-Validation: 6B6F4A89CF4A21169438E1D4BA206A1B
Thread 8: Adding header *Client-DAAP-Validation=6B6F4A89CF4A21169438E1D4BA206A1B*
Added *Client-DAAP-Validation=6B6F4A89CF4A21169438E1D4BA206A1B*
Thread 8: Read: Client-DAAP-Request-ID: 8
Thread 8: Adding header *Client-DAAP-Request-ID=8*
Added *Client-DAAP-Request-ID=8*
Thread 8: Read: x-audiocast-udpport: 61486
Thread 8: Adding header *x-audiocast-udpport=61486*
Added *x-audiocast-udpport=61486*
Thread 8: Read: icy-metadata: 1
Thread 8: Adding header *icy-metadata=1*
Added *icy-metadata=1*
Thread 8: Read: Connection: close
Thread 8: Adding header *Connection=close*
Added *Connection=close*
Thread 8: Read:
Thread 8: Headers parsed!
Checking to see if connection matches close
And it DOES!
Thread 8: Connection type HTTP/1.1
: Connection: non-persist
Thread 8: Original URI: daap://192.168.0.15:3689/databases/1/items/29.mp3
Thread 8: Translated URI: /databases/1/items/29.mp3
Thread 8: Preparing to find handler
Checking /databases/1/items/29.mp3 against handler for /
Thread 8: URI Match!
Thread 8: Time is 1212446771 seconds after epoch
Thread 8: Setting time header
Added *Date=Mon, 2 Jun 2008 22:46:11 GMT*
Added *Connection=close*
Added *Server=mt-daapd/svn-1696*
Added *Content-Type=text/html*
Added *Content-Language=en_us*
Thread 8: Using non-default handler
in main_auth
Checking url /databases/1/items/29.mp3
Checking url /databases/1/items/29.mp3
Dispatching auth for /databases/1/items/29.mp3 to plugin
Checking url /databases/1/items/29.mp3
Checking url /databases/1/items/29.mp3
Dispatching /databases/1/items/29.mp3 to daap/svn-1696
in main_handler
Checking url /databases/1/items/29.mp3
Checking url /databases/1/items/29.mp3
Dispatching /databases/1/items/29.mp3 to plugin
Checking url /databases/1/items/29.mp3
Checking url /databases/1/items/29.mp3
Dispatching /databases/1/items/29.mp3 to daap/svn-1696
Getting uri…
Mallocing privinfo…
Added *Accept-Ranges=bytes*
Added *DAAP-Server=firefly/svn-1696*
Updating Content-Type from text/html to application/x-dmap-tagged
Added *Cache-Control=no-cache*
Added *Expires=-1*
Tokenizing url
Found 17 elements
Checking reponse 0
Checking reponse 1
Checking reponse 2
Checking reponse 3
Checking reponse 4
Checking reponse 5
Checking reponse 6
Checking reponse 7
Checking reponse 8
Checking reponse 9
Found it! Index: 9
Executing: select * from songs where id=29
Creating new db handle
Opening file:///home/media/music/iTunes/Rhianna/Good+Girl+Gone+Bad/06++Rihanna+-+Hate+That+I+Love+You+%5bFeat.+Ne-Yo%5d.mp3
Checking handler for file
opening /home/media/music/iTunes/Rhianna/Good Girl Gone Bad/06 Rihanna – Hate That I Love You [Feat. Ne-Yo].mp3
Thread 8: Length of file (remaining): 5258551
Updating Content-Type from application/x-dmap-tagged to audio/mp3
Added *Content-Length=5258551*
Updating Connection from close to Close
Emitting reponse header Content-Length: 5258551
Emitting reponse header Expires: -1
Emitting reponse header Cache-Control: no-cache
Emitting reponse header DAAP-Server: firefly/svn-1696
Emitting reponse header Accept-Ranges: bytes
Emitting reponse header Content-Language: en_us
Emitting reponse header Content-Type: audio/mp3
Emitting reponse header Server: mt-daapd/svn-1696
Emitting reponse header Connection: Close
Emitting reponse header Date: Mon, 2 Jun 2008 22:46:11 GMT
Entering config_set_status
Exiting config_set_status
Session 0: Streaming file ’06 Rihanna – Hate That I Love You [Feat. Ne-Yo].mp3′ to 192.168.0.209 (offset 0)
timeout in select
timeout in select
timeout in select
timeout in select
timeout in select
timeout in select

/S

[Anonymous]

Added *HTTP_USER=admin*
Added *HTTP_PASSWD=mt-daapd*
in main_handler
Checking url /xml-rpc
Checking url /xml-rpc
Dispatching /xml-rpc to config handler
Entering config_handler
Entering config_set_status
Exiting config_set_status
Updating Connection from keep-alive to close
Entering config_set_status
Exiting config_set_status
Added *Cache-Control=no-cache*
Added *Expires=-1*
Updating Content-Type from text/html to text/xml; charset=utf-8
Emitting reponse header Expires: -1
Emitting reponse header Cache-Control: no-cache
Emitting reponse header Content-Language: en_us
Emitting reponse header Content-Type: text/xml; charset=utf-8
Emitting reponse header Server: mt-daapd/svn-1696
Emitting reponse header Connection: close
Emitting reponse header Date: Tue, 3 Jun 2008 00:04:47 GMT
Status inquiry
Processing rendezvous message
Returning status 0
Executing: select count(*) FROM songs
Creating new db handle
Thread 806: xml-rpc served
Entering config_set_status
Exiting config_set_status
Thread 806: Terminating
Thread 806: Freeing request headers
Thread 806: Freeing response headers
Thread 806: Freeing request vars
Thread 806: Closing fd
With thread 806 exiting, 0 are still running
Got shutdown signal.
Stopping gracefully
Stopping rendezvous daemon
Processing rendezvous message
Stopping mDNS
Closing database
Done!
Exiting
Deregistered service 2
Deregistered service 1
Deregistered service 0
Callback: Silikone Music Server_http_tcplocal Memory Free
Callback: Silikone Music Server_rsp_tcplocal Memory Free
Callback: Silikone Music Server_daap_tcplocal Memory Free
Finished with status 0, result 0

[EVILRipper]

This is a tough one to track down.
Does this randomly occur with any song?
Cuz my first guess would be a corrupted file killing FF.

Though another thing that concerns me is the “Got shutdown signal. ” line in the second log.

timeout in select… I have no idea what that could mean while streaming a file.

[Anonymous]

As far as I understand FF is only involved if we need to transcode the files. Serving MP3 does not require FF – right ?

The files play ok – as far as I can hear.

The problem seems to be related to thread 0 and thread 2. Once they both have died the system dies. Well not actually dead dead, but the main program is still alive, the web page works fine, but the server is no longer available in iTunes and no songs can be served. It can happen anywhere in a song.

I have suspected the pThreads library. This machine is running SuSE 10.2 which offers pThreads 2.5 (use getconf GNU_LIBPTHREAD_VERSION), while my SuSE 10.3 at work offer version 2.6.1. I’ll try today at work to see if this does do a difference.

What pthreads has the program been known to work with ?

/S

[Anonymous]

Just one more thing.

The got shutdown is the manual kill that I did after the crash of the server.

The actual problem is the write problem that causes the system to fail.
It is near the end of the first log extract.

/S

[fizze]

Well I suppose it wants to update the playcount, or send all the metadata to the client. *weird*

As you are running it on Suse, did you try to play any stuff via DAAP thru banshee or rhythmbox? Same problem?

Is it just that one mp3, or does it happen at random?

[Anonymous]

Here is the actual shutdown of the sound stream.

2008-06-03 10:19:15 (b7cceb90): timeout in select
2008-06-03 10:19:16 (b7cceb90): timeout in select
2008-06-03 10:19:17 (b7cceb90): timeout in select
2008-06-03 10:19:18 (b7cceb90): timeout in select
2008-06-03 10:19:19 (b7cceb90): timeout in select
2008-06-03 10:19:20 (b7cceb90): timeout in select
2008-06-03 10:19:21 (b7cceb90): timeout in select
2008-06-03 10:19:22 (b7cceb90): timeout in select
2008-06-03 10:19:23 (b7cceb90): timeout in select
2008-06-03 10:19:24 (b7cceb90): timeout in select
2008-06-03 10:19:25 (b7cceb90): Thread 0: could not read: unknown internal error
2008-06-03 10:19:25 (b7cceb90): Thread 0: Terminating
2008-06-03 10:19:25 (b7cceb90): Thread 0: Freeing request headers
2008-06-03 10:19:25 (b7cceb90): Thread 0: Freeing response headers
2008-06-03 10:19:25 (b7cceb90): Thread 0: Freeing request vars
2008-06-03 10:19:25 (b7cceb90): Thread 0: Closing fd
2008-06-03 10:19:25 (b7cceb90): With thread 0 exiting, 1 are still running
2008-06-03 10:19:25 (b6cccb90): Write error: Connection reset by peer
2008-06-03 10:19:25 (b6cccb90): Error copying file to remote…
2008-06-03 10:19:25 (b6cccb90): Entering config_set_status
2008-06-03 10:19:25 (b6cccb90): Exiting config_set_status
2008-06-03 10:19:25 (b6cccb90): Thread 13: Terminating
2008-06-03 10:19:25 (b6cccb90): Thread 13: Freeing request headers
2008-06-03 10:19:25 (b6cccb90): Thread 13: Freeing response headers
2008-06-03 10:19:25 (b6cccb90): Thread 13: Freeing request vars
2008-06-03 10:19:25 (b6cccb90): Thread 13: Closing fd
2008-06-03 10:19:25 (b6cccb90): With thread 13 exiting, 0 are still running

The problem happens with all sorts of mp3’s. There seems to be no pattern wrt the mp3.

But I got to wonder if the “Timeout in select” is a database problem. The one thing that I do keep running is the web interface, which is posting a large number of events in the log. Is there a race condition between the two ? I’m using sqlite 3.3.8-14.

I’ll try the other clients to see if this is an itunes related problem.

/S

[Anonymous]

I installed Banshee and configured it to use the daap service.

Starts up fine and finds the server, loads the library and presents it, but when I start to play a song it shows another problem in the system. Perhaps they are related – they certainly look to be.

2008-06-03 10:52:42 (b7d68b90): Executing: select * from songs where id=1
2008-06-03 10:52:42 (b7d68b90): Opening file:///home/media/music/iTunes/Hannah+M
ontana+2+-+Meet+Miley+Cyrus/10+True+Friend.mp3
2008-06-03 10:52:42 (b7d68b90): Checking handler for file
2008-06-03 10:52:42 (b7d68b90): opening /home/media/music/iTunes/Hannah Montana
2 – Meet Miley Cyrus/10 True Friend.mp3
2008-06-03 10:52:42 (b7d68b90): Thread 8: Length of file (remaining): 3084327
2008-06-03 10:52:42 (b7d68b90): Updating Content-Type from application/x-dmap-ta
gged to audio/mp3
2008-06-03 10:52:42 (b7d68b90): Added *Content-Length=3084327*
2008-06-03 10:52:42 (b7d68b90): Updating Connection from close to Close
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Content-Length: 3084327
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Expires: -1
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Cache-Control: no-cache
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header DAAP-Server: firefly/svn
-1696
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Accept-Ranges: bytes
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Content-Language: en_us
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Content-Type: audio/mp3
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Server: mt-daapd/svn-169
6
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Connection: Close
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Date: Tue, 3 Jun 2008 17
:52:42 GMT
2008-06-03 10:52:42 (b7d68b90): Entering config_set_status
2008-06-03 10:52:42 (b7d68b90): Exiting config_set_status
2008-06-03 10:52:42 (b7d68b90): Session 0: Streaming file ’10 True Friend.mp3′ t
o 192.168.0.15 (offset 0)
2008-06-03 10:52:42 (b7d68b90): Write error: Connection reset by peer
2008-06-03 10:52:42 (b7d68b90): Error copying file to remote…
2008-06-03 10:52:42 (b7d68b90): Entering config_set_status
2008-06-03 10:52:42 (b7d68b90): Exiting config_set_status
2008-06-03 10:52:42 (b7d68b90): Thread 8: Terminating
2008-06-03 10:52:42 (b7d68b90): Thread 8: Freeing request headers
2008-06-03 10:52:42 (b7d68b90): Thread 8: Freeing response headers
2008-06-03 10:52:42 (b7d68b90): Thread 8: Freeing request vars
2008-06-03 10:52:42 (b7d68b90): Thread 8: Closing fd
2008-06-03 10:52:42 (b7d68b90): With thread 8 exiting, 0 are still running
2008-06-03 10:52:42 (b7567b90): Got listen socket 9
2008-06-03 10:52:42 (b7d68b90): Thread 9:
2008-06-03 10:52:42 (b7d68b90): Request: GET /databases/1/items/2.mp3?session-id
=1& HTTP/1.1^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: Accept-Encoding: gzip^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding header *Accept-Encoding=gzip*
2008-06-03 10:52:42 (b7d68b90): Added *Accept-Encoding=gzip*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: Accept: */*^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding header *Accept=*/**
2008-06-03 10:52:42 (b7d68b90): Added *Accept-Encoding=gzip*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: Accept: */*^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding header *Accept=*/**
2008-06-03 10:52:42 (b7d68b90): Added *Accept=*/**
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: User-Agent: iTunes/4.6 (Windows; N)^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding header *User-Agent=iTunes/4.6 (Windows; N)*
2008-06-03 10:52:42 (b7d68b90): Added *User-Agent=iTunes/4.6 (Windows; N)*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: Client-DAAP-Version: 3.0^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding header *Client-DAAP-Version=3.0*
2008-06-03 10:52:42 (b7d68b90): Added *Client-DAAP-Version=3.0*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: Client-DAAP-Validation: AEAF7713008720C526E9043305378A0B^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding header *Client-DAAP-Validation=AEAF7713008720C526E9043305378A0B*
2008-06-03 10:52:42 (b7d68b90): Added *Client-DAAP-Validation=AEAF7713008720C526E9043305378A0B*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: Client-DAAP-Access-Index: 2^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding header *Client-DAAP-Access-Index=2*
2008-06-03 10:52:42 (b7d68b90): Added *Client-DAAP-Access-Index=2*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: Client-DAAP-Request-ID: 12^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding header *Client-DAAP-Request-ID=12*
2008-06-03 10:52:42 (b7d68b90): Added *Client-DAAP-Request-ID=12*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: Connection: close^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding header *Connection=close*
2008-06-03 10:52:42 (b7d68b90): Added *Connection=close*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: Host: 192.168.0.15:3689^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding header *Host=192.168.0.15:3689*
2008-06-03 10:52:42 (b7d68b90): Added *Host=192.168.0.15:3689*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: Authorization: Basic bm9uZTo=^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding header *Authorization=Basic bm9uZTo=*
2008-06-03 10:52:42 (b7d68b90): Added *Authorization=Basic bm9uZTo=*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Read: ^M
2008-06-03 10:52:42 (b7d68b90): Thread 9: Headers parsed!
2008-06-03 10:52:42 (b7d68b90): Checking to see if connection matches close
2008-06-03 10:52:42 (b7d68b90): And it DOES!
2008-06-03 10:52:42 (b7d68b90): Thread 9: Connection type HTTP/1.1^M
: Connection: non-persist
2008-06-03 10:52:42 (b7d68b90): Thread 9: parsing GET args
2008-06-03 10:52:42 (b7d68b90): Thread 9: Adding arg session-id = 1
2008-06-03 10:52:42 (b7d68b90): Added *session-id=1*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Bad arg:
2008-06-03 10:52:42 (b7d68b90): Thread 9: Done parsing GET/POST args!
2008-06-03 10:52:42 (b7d68b90): Thread 9: Original URI: /databases/1/items/2.mp3
2008-06-03 10:52:42 (b7d68b90): Thread 9: Translated URI: /databases/1/items/2.mp3
2008-06-03 10:52:42 (b7d68b90): Thread 9: Preparing to find handler
2008-06-03 10:52:42 (b7d68b90): Checking /databases/1/items/2.mp3 against handler for /
2008-06-03 10:52:42 (b7d68b90): Thread 9: URI Match! 2008-06-03 10:52:42 (b7d68b90): Thread 9: Time is 1212515562 seconds after epoch
2008-06-03 10:52:42 (b7d68b90): Thread 9: Setting time header 2008-06-03 10:52:42 (b7d68b90): Added *Date=Tue, 3 Jun 2008 17:52:42 GMT*
2008-06-03 10:52:42 (b7d68b90): Added *Connection=close* 2008-06-03 10:52:42 (b7d68b90): Added *Server=mt-daapd/svn-1696*
2008-06-03 10:52:42 (b7d68b90): Added *Content-Type=text/html* 2008-06-03 10:52:42 (b7d68b90): Added *Content-Language=en_us*
2008-06-03 10:52:42 (b7d68b90): Thread 9: Using non-default handler 2008-06-03 10:52:42 (b7d68b90): in main_auth
2008-06-03 10:52:42 (b7d68b90): Checking url /databases/1/items/2.mp3 2008-06-03 10:52:42 (b7d68b90): Checking url /databases/1/items/2.mp3
2008-06-03 10:52:42 (b7d68b90): Dispatching auth for /databases/1/items/2.mp3 to plugin
2008-06-03 10:52:42 (b7d68b90): Checking url /databases/1/items/2.mp3 2008-06-03 10:52:42 (b7d68b90): Checking url /databases/1/items/2.mp3
2008-06-03 10:52:42 (b7d68b90): Dispatching /databases/1/items/2.mp3 to daap/svn-1696
2008-06-03 10:52:42 (b7d68b90): in main_handler 2008-06-03 10:52:42 (b7d68b90): Checking url /databases/1/items/2.mp3
2008-06-03 10:52:42 (b7d68b90): Checking url /databases/1/items/2.mp3 2008-06-03 10:52:42 (b7d68b90): Dispatching /databases/1/items/2.mp3 to plugin
2008-06-03 10:52:42 (b7d68b90): Checking url /databases/1/items/2.mp3 2008-06-03 10:52:42 (b7d68b90): Checking url /databases/1/items/2.mp3
2008-06-03 10:52:42 (b7d68b90): Dispatching /databases/1/items/2.mp3 to daap/svn-1696
2008-06-03 10:52:42 (b7d68b90): Getting uri… 2008-06-03 10:52:42 (b7d68b90): Mallocing privinfo…
2008-06-03 10:52:42 (b7d68b90): Added *Accept-Ranges=bytes* 2008-06-03 10:52:42 (b7d68b90): Added *DAAP-Server=firefly/svn-1696*
2008-06-03 10:52:42 (b7d68b90): Updating Content-Type from text/html to application/x-dmap-tagged
2008-06-03 10:52:42 (b7d68b90): Added *Cache-Control=no-cache* 2008-06-03 10:52:42 (b7d68b90): Added *Expires=-1*
2008-06-03 10:52:42 (b7d68b90): Tokenizing url
2008-06-03 10:52:42 (b7d68b90): Found 17 elements
2008-06-03 10:52:42 (b7d68b90): Checking reponse 0 2008-06-03 10:52:42 (b7d68b90): Checking reponse 1
2008-06-03 10:52:42 (b7d68b90): Checking reponse 2 2008-06-03 10:52:42 (b7d68b90): Checking reponse 3
2008-06-03 10:52:42 (b7d68b90): Checking reponse 4 2008-06-03 10:52:42 (b7d68b90): Checking reponse 5
2008-06-03 10:52:42 (b7d68b90): Checking reponse 6 2008-06-03 10:52:42 (b7d68b90): Checking reponse 7
2008-06-03 10:52:42 (b7d68b90): Checking reponse 8 2008-06-03 10:52:42 (b7d68b90): Checking reponse 9
2008-06-03 10:52:42 (b7d68b90): Found it! Index: 9
2008-06-03 10:52:42 (b7d68b90): Executing: select * from songs where id=2
2008-06-03 10:52:42 (b7d68b90): Creating new db handle
2008-06-03 10:52:42 (b7d68b90): Opening file:///home/media/music/iTunes/Hannah+Montana+2+-+Meet+Miley+Cyrus/12+East+Northumberland+High.mp3
2008-06-03 10:52:42 (b7d68b90): Checking handler for file
2008-06-03 10:52:42 (b7d68b90): opening /home/media/music/iTunes/Hannah Montana 2 – Meet Miley Cyrus/12 East Northumberland High.mp3
2008-06-03 10:52:42 (b7d68b90): Thread 9: Length of file (remaining): 3326351
2008-06-03 10:52:42 (b7d68b90): Updating Content-Type from application/x-dmap-tagged to audio/mp3
2008-06-03 10:52:42 (b7d68b90): Added *Content-Length=3326351*
2008-06-03 10:52:42 (b7d68b90): Updating Connection from close to Close
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Content-Length: 3326351
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Expires: -1
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Cache-Control: no-cache
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header DAAP-Server: firefly/svn-1696
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Accept-Ranges: bytes
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Content-Language: en_us
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Content-Type: audio/mp3
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Server: mt-daapd/svn-1696
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Connection: Close
2008-06-03 10:52:42 (b7d68b90): Emitting reponse header Date: Tue, 3 Jun 2008 17:52:42 GMT
2008-06-03 10:52:42 (b7d68b90): Entering config_set_status
2008-06-03 10:52:42 (b7d68b90): Exiting config_set_status
2008-06-03 10:52:42 (b7d68b90): Session 0: Streaming file ’12 East Northumberland High.mp3′ to 192.168.0.15 (offset 0)
2008-06-03 10:52:43 (b7d68b90): Write error: Connection reset by peer
2008-06-03 10:52:43 (b7d68b90): Error copying file to remote…
2008-06-03 10:52:43 (b7d68b90): Entering config_set_status
2008-06-03 10:52:43 (b7d68b90): Exiting config_set_status
2008-06-03 10:52:43 (b7d68b90): Thread 9: Terminating

and then on and on and on …….

Looks like a permission problem somewhere to me. Where is the socket that mt-daapd writes the streamed music to created. I have Banshee on the same machine as the server – and its running as a real user – not just nobody.

Suggestions ??

[fizze]

This is really a tough one. 😕
Interesting. There is no known race condition with Sqlite3. Although debuglevel 9 puts a lot of stress to the db, maybe try again with loglevel 0 just for kicks.

I haven’t got the slightest clue who creates the socket. Could be server, or clientside. Shouldn’t be a permission issue, since firefly can open port 3689 alright. And banshee can browse alright so that’s not it.

Did you set up iptables or any other firewall appliances? Are you running SELinux?
Do you have enough free space left on your root fs?

Banshee cannot do transcoding stuff, and also not do playlists via DAAP.
But as long as you’re streaming mp3s you should be good.

About transcoding you mentioned earlier: FF is always “involved” but when you transcode, it invokes ffmpeg, or the ssc-scripts and streams a wav. So its all the same really. You could even transcode mp3 to wav, just for kicks.

😕

[EVILRipper]

I’m having a look in the code.
As it is quite complex, I can’t figure out that much;

Several sockets are added to a list.
While these sockets are busy, a function is called to wait for them to complete.
However, when running a function to check the status, the timeout is triggered.
Function to check socket: http://msdn.microsoft.com/en-us/library/ms740141(VS.85).aspx

So, to return to non-technically:
A connection is open. The connection status is checked, but hits a timeout. That’s what causing the “timeout on select” error. Possibly, this is causing FF to hang/crash.

My guess: The problem’s cause is not in FF. Something else is making the connection timeout. However, I have no clue what could be causing it.

For anybody else who wants to dig in the code:
Source: io.c
line: 3014 is where the error occurs.

[Author]

Posts