Timout in Select

  • Post date

FireFly Media Server › Firefly Media Server Forums › Firefly Media Server › Nightlies Feedback › Timout in Select

Viewing 10 posts - 1 through 10 (of 14 total)
1 2
  • Author
    Posts
  • 02/06/2008 at 11:47 PM #2476
    Anonymous
    Inactive

    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

    03/06/2008 at 12:08 AM #17125
    Anonymous
    Inactive

    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

    03/06/2008 at 8:37 AM #17126
    EVILRipper
    Participant

    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.

    03/06/2008 at 3:55 PM #17127
    Anonymous
    Inactive

    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

    03/06/2008 at 4:14 PM #17128
    Anonymous
    Inactive

    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

    03/06/2008 at 5:19 PM #17129
    fizze
    Participant

    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?

    03/06/2008 at 5:25 PM #17130
    Anonymous
    Inactive

    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

    03/06/2008 at 6:01 PM #17131
    Anonymous
    Inactive

    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 ??

    03/06/2008 at 6:12 PM #17132
    fizze
    Participant

    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.

    😕

    03/06/2008 at 9:16 PM #17133
    EVILRipper
    Participant

    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
Viewing 10 posts - 1 through 10 (of 14 total)
1 2
  • The forum ‘Nightlies Feedback’ is closed to new topics and replies.