Bug 964 - Occasional reconnects (possibly associated with FLAC playback)
: Occasional reconnects (possibly associated with FLAC playback)
Status: RESOLVED FIXED
Product: SB 2/3
Classification: Unclassified
Component: Audio
: unspecified
: PC Windows XP
: P1 major (vote)
: ---
Assigned To: Vidur Apparao
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2005-03-07 16:26 UTC by Vidur Apparao
Modified: 2008-12-18 11:36 UTC (History)
1 user (show)

See Also:
Category: ---


Attachments
debug log of reconnect (5.56 KB, text/plain)
2005-03-07 16:35 UTC, Vidur Apparao
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Vidur Apparao 2005-03-07 16:26:06 UTC
I've noticed spontaneous reconnects when playing FLAC over wireless. I'm not
sure it's necessarily specific to FLAC playback. Other details:

AP: Netgear WGR614
Mode: b/g
WEP: 64-bit
Comment 1 Vidur Apparao 2005-03-07 16:35:20 UTC
Created attachment 310 [details]
debug log of reconnect

A SB2 debug log showing the reconnect. In this case, the control connection
died because we hit a 10 second retransmission timeout. A packet was received
on the socket less than 10 seconds before the timeout, indicating that the
connection was still alive. We may want to consider disabling the timeout to
better deal with crappy wireless network periods.

I've also seen the control connection die because of a FIN flag coming from the
server...will try to get a log of that.
Comment 2 Dan Sully 2005-03-09 11:54:51 UTC
I'm seeing this as well - streaming FLAC over wired.

Control channel is still there, streaming socket has dropped.
Comment 3 Vidur Apparao 2005-03-09 11:56:27 UTC
I've now seen it happen with MP3 as well. This time with a Linksys WRT54G. So it
doesn't seem to be format or AP specific.
Comment 4 Dan Sully 2005-03-09 12:27:28 UTC
2005-03-09 11:58:21.0403 openSong: this is an flc file:
file:///bits/music/Banco%20de%20Gaia/Igizeh/Banco%20de%20Gaia%20-%2001%20-%20Seti%20I.flac
2005-03-09 11:58:21.0404   file type: flc format: flc inrate: 936.619262472885
maxRate: 0
2005-03-09 11:58:21.0404   command: -
2005-03-09 11:58:21.0405 openSong: opening file /bits/music/Banco de
Gaia/Igizeh/Banco de Gaia - 01 - Seti I.flac
2005-03-09 11:58:21.0407  seeking in 251 into /bits/music/Banco de
Gaia/Igizeh/Banco de Gaia - 01 - Seti I.flac
2005-03-09 11:58:21.0408 Streaming with format: flc
2005-03-09 11:58:21.0497 00:04:20:ba:a7:06 New play mode: play
2005-03-09 11:58:21.0512 00:04:20:ba:a7:06: Current playmode: play
2005-03-09 11:58:21.2103 Got a track starting event
2005-03-09 11:58:21.2104 Song 0 has now started playing
2005-03-09 11:58:21.2106 Song queue is now 0
2005-03-09 12:06:22.6981 Reduced chunksize to 24206 at end of file (61169294 -
61145088)
2005-03-09 12:06:22.9177 Reduced chunksize to 251 at end of file (61169294 -
61169043)
2005-03-09 12:06:22.9178 Read to end of file or pipe
2005-03-09 12:06:22.9180 end of file or error on socket, opening next song,
(song pos: 61169043(tell says: . 61169294), totalbytes: 61169294)
2005-03-09 12:06:22.9180 opening next song...
2005-03-09 12:06:22.9184 the next song is number 1, was 0
2005-03-09 12:06:22.9190 undermax = 1, type = flc, squeezebox2 =
00:04:20:ba:a7:06, lame = /usr/bin/lame
2005-03-09 12:06:22.9191 checking formats for: flc-flc-squeezebox2-00:04:20:ba:a7:06
2005-03-09 12:06:22.9195 Checking to see if
flc-flc-squeezebox2-00:04:20:ba:a7:06 is enabled
2005-03-09 12:06:22.9196    enabled
2005-03-09 12:06:22.9196 checking formats for: flc-flc-*-00:04:20:ba:a7:06
2005-03-09 12:06:22.9197 Checking to see if flc-flc-*-00:04:20:ba:a7:06 is enabled
2005-03-09 12:06:22.9197    enabled
2005-03-09 12:06:22.9198 checking formats for: flc-flc-squeezebox2-*
2005-03-09 12:06:22.9198 Checking to see if flc-flc-squeezebox2-* is enabled
2005-03-09 12:06:22.9198    enabled
2005-03-09 12:06:22.9199 checking formats for: flc-flc-*-*
2005-03-09 12:06:22.9199 Checking to see if flc-flc-*-* is enabled
2005-03-09 12:06:22.9199    enabled
2005-03-09 12:06:22.9200   Found command: -
2005-03-09 12:06:22.9202 Matched Format: flc Type: flc Command: -
2005-03-09 12:06:22.9203 playing out before starting next song. (old format:
flc, new: flc)
2005-03-09 12:06:22.9205 Backtrace:

   frame 0: Slim::Player::Source::playmode
(/home/dsully/dev/slim/trunk/Slim/Player/Source.pm line 760)
   frame 1: Slim::Player::Source::gotoNext
(/home/dsully/dev/slim/trunk/Slim/Player/Source.pm line 1641)
   frame 2: Slim::Player::Source::readNextChunk
(/home/dsully/dev/slim/trunk/Slim/Player/Source.pm line 523)
   frame 3: Slim::Player::Source::nextChunk
(/home/dsully/dev/slim/trunk/Slim/Web/HTTP.pm line 1214)
   frame 4: Slim::Web::HTTP::sendStreamingResponse
(/home/dsully/dev/slim/trunk/Slim/Networking/Select.pm line 124)
   frame 5: Slim::Networking::Select::select (slimserver.pl line 569)
   frame 6: main::idle (slimserver.pl line 512)
   frame 7: main::main (slimserver.pl line 1061)

2005-03-09 12:06:22.9206 00:04:20:ba:a7:06: Switching to mode playout-play from play
2005-03-09 12:06:22.9207 00:04:20:ba:a7:06 New play mode: playout-play
2005-03-09 12:06:22.9214 00:04:20:ba:a7:06: Current playmode: playout-play
2005-03-09 12:06:22.9219 00:04:20:ba:a7:06: Can't opennext, returning no chunk.
Comment 5 Vidur Apparao 2005-03-09 15:44:58 UTC
Based on a conversation with Dan, it seems like his problem may be unrelated.
The track plays through, but the server doesn't start the next one (the player
isn't sending out a decoder underrun notification?).
Comment 6 Blackketter Dean 2005-03-23 13:17:43 UTC
Apparently fixed.  Reopen if it happens again.