Bugzilla – Bug 13380
sync not working / breaks with vorbis files
Last modified: 2010-05-20 14:09:58 UTC
please also see this thread for a summary and more discussion: http://forums.slimdevices.com/showthread.php?t=65870 after just upgrading to 7.3.3. and still not getting better i decided it is time to file a bug report. my setup: Version: 7.3.3 - 27044 @ Mon Jun 15 15:03:29 PDT 2009 Hostname: Turbonas Server IP Address: 192.168.0.102 Server HTTP Port Number: 9001 Operating system: Linux - EN - iso-8859-1 Platform Architecture: armv5tejl-linux Perl Version: 5.8.8 - armv5tejl-linux-thread-multi MySQL Version: 5.0.27 Total Players Recognized: 3 This is a qnap turbonas 409 running SSOTS 3.15. there are two SB3s running FW 127 and one softsqueeze, which i do NOT sync. both SB3s have been wired for testing this issue to eliminate the WLAN as a problem source. the problem is reproduceable regardless of the vorbis encoder used: GTune3b2, aoTuV and xiph reference. symptoms: 1. playlists containing vorbis files cause the players to drift apart over time. track transitions seem to aggravate the problem (i am using crossfade). drift is noticeable usually after 10-20 mins. or 3-4 tracks. sync often (but not always) returns when an MP3 comes up in the playlist, only to drift again after subsequent vorbis files. 2. when i use the remote AND vorbis files are playing, sync often breaks immediately. this includes skipping and scanning tracks as well as loading playlists (provided the loaded playlist starts on a vorbis file) 3. when i use the Web UI instead of the remote this does not seem to happen, even with vorbis files. 4. when i play MP3 and/or FLAC only playlists this does not seem to happen, even using the remote. sync will not drift either and stay rock solid over many hours. 5. i can sometimes re-sync broken players by pointing the remote at the "other" SB3 and skipping one track ahead. meaning: alternately controlling one and then the other SB3. this even with vorbis files. 6. re-syncing is also possible by using the WebUI to skip some tracks ahead. 7. re-syncing is 99% accurate when skipping to an MP3 track in the playlist either through remote or web UI. this (short of restarting SC) seems to be the most reliable way of re-syncing. 8. my earier statement of cold-booting the SBs to re-sync (see the discussion thread) has proven untrue. (maybe due to my recent update to 7.3.3.) as a matter of fact, cold-booting an SB and letting it re-join the sync-group has proven to be an almost sure-fire way of _breaking_ sync, when playing a vorbis file. my SC is already configured for logging network.protocol network.protocol.slimproto player.streaming player.sync both SBs have been playing a mixed MP3/vorbis playlist all night and were apart by about 3-4 seconds this morning. i have attached the last 1000 lines of the server log to this bug. please let me know if and what else i can do to help nail this bug!
Created attachment 5613 [details] last 1000 lines of server log the enitre log is available on request.
so sooner have i filed this bug report, when sync even drifts apart on an MP3-only playlist... :-( this is odd. yesterday, i had the very same playlist running for 2+ hrs without any sync problems whatsoever. even now, i am not able to reproduce the drift with an MP3 playlist anymore. to verify that nothing on the server (my qnap) is blocking/stressing SC too much, i ran some artificial stress tests (large SMB file copies). result: buffer ran empty, SBs stopped playing, but immediately resumed _fully synced_ after i stopped stressing the server. please remember that both players are _wired_ during all of these tests. i see two more potential causes: 1. crossfade in combo with sync -> turned crossfade to "off" and am re-testing now 2. my qnap and/or the perl/linux distribution -> installing SC 7.3.3. on a windows box and will re-test on it
i just did a completely clean re-install of SC 7.3.3. to avoid junk being dragged along from previous versions. for example, my prefs files were still from my old windows system... after battling with SSOTS, i managed to get SSOTS 3.18 + SC 7.3.3. running. and indeed, sync _appears_ to be MUCH better now. unfortunately, it is still not 100% good, because after ~2 hrs of synced play there were two instances where sync broke on a vorbis file. both times, sync returned when an MP3 file came up in the playlist. since the new install, i can actually _hear_ the sync mechanism work, because (again on vorbis files) playback sometimes starts with a big gap between players, and 1-2 seconds later i can hear one of them skipping and catching up. also, when my server is very busy, sync sometimes lags. but whenever the server load drops again, i can hear the players re-sync. which is GOOD and exactly what i am expecting. but sometimes it seems as if SC just "forgets" to keep sync when playing a vorbis file, and suddenly remembers when an MP3 comes up.
When you get the problem, please can you enable logging at level player.sync=debug and then attach the logfile to this bug report. If the problem is easily reproducible across track boundaries then the combination of player.sync=debug, player.source=info and network.protocol.slimproto=info would be useful. Off hand, I cannot think why Vorbis files should behave differently to MP3s. However, you mention that you use crossfading. Certainly this will cause some problems at maximum crossfade interval of 10s, but such problems should be rectified within a second or two. I recommend that you set the crossfade interval (for both players) to no more than 8s.
i haven't had time to do more extensive testing (sorry!), but i _think_ i have been seeing a pattern now: sync breaks when: 1. transitioning TO a vorbis file (higher bitrate files are more likely to cause this) 2. AND the qnap's processor is heavily loaded. this i discovered while moving lots of multimedia files to/from the qnap, while players were synced. in these instances, sync only seems to return when an MP3 file comes up. when one does, sync returns and keeps on working even on subsequent vorbis files. loading the processor _during_ a vorbis track will also cause sync to drift audibly. so far it always seems to return tho (also audibly), provided the CPU load drops back down to normal BEFORE the next song transition. does that help in any way?
(In reply to comment #5) > does that help in any way? Not really without the logs requested earlier. I am at something of a loss to understand why Vorbis (Ogg) files should be relevant at all. When sync breaks, is it by a few ms, or several seconds? In which case can you estimate (or time) by how much? What player types are you using?
Sorry, just saw that you have already specified the play types: a pair of SB3s.
The only way Vorbis might matter is that it has a decoder startup delay, but with 2 identical players that shouldn't be an issue.
Update hours
I have been unable to reproduce this at all. Can QA take a look?
guys - i had completely forgotten about this bug. which is a good thing, because that means i have not been experiencing it anymore. no idea why. for a time it was happening on a daily basis and sometime it just stopped. don't even remember when... please feel free to close this bug.
I can't repro this bug with 7.5.1 r30796. Also the OP notes she is not seeing it any more. :) If anyone does see it again, please feel free to re-open!