Bug 10957 - Sync Problems
: Sync Problems
Status: CLOSED FIXED
Product: Logitech Media Server
Classification: Unclassified
Component: Sync
: 7.3.2
: Macintosh MacOS X 10.5
: P2 normal (vote)
: 7.4.0
Assigned To: Squeezebox QA Team email alias
: Verify_74
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2009-02-04 12:14 UTC by andre strebel
Modified: 2009-10-05 14:36 UTC (History)
2 users (show)

See Also:
Category: ---


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description andre strebel 2009-02-04 12:14:38 UTC
- since two weeks i have this problen what you see in this email.
- i have synchronize 7 players, the problem players are a squeezebox and a new transporter. sometimes the new song start, after seconds it restart and restart and this with never end... again, again..
- i have reinstalled the players but i have the same problem.
- yesterday i make the update to 7.3.2 - 24695, the same problem..
- what can i do?
- on my house i have 11 player installed and 7 are synchronized.


please help me...., andré


09-02-04 06:29:57.8284] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:04:20:10:0d:88
[09-02-04 06:39:10.1577] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-04 07:00:24.5310] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-04 07:00:24.5333] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-04 07:00:24.5474] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-04 07:00:24.6654] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-04 07:00:24.6747] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-04 07:00:25.6284] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-04 07:01:01.0871] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:04:20:10:0d:88
[09-02-04 07:01:01.1053] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:00:5d:ff:ff:fe
[09-02-04 07:05:33.2576] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:00:5d:ff:ff:fe, will retry in 9600
[09-02-04 07:10:21.0697] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:04:20:10:0d:88, will retry in 10050
[09-02-04 09:45:33.1038] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:00:5d:ff:ff:fe, will retry in 9630
[09-02-04 09:57:51.0682] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:04:20:10:0d:88, will retry in 10080
[09-02-04 12:26:03.1008] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:00:5d:ff:ff:fe, will retry in 9660
[09-02-04 12:45:51.1729] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:04:20:10:0d:88, will retry in 10110
[09-02-04 15:07:03.1960] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:00:5d:ff:ff:fe, will retry in 9690
[09-02-04 15:34:21.0907] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:04:20:10:0d:88, will retry in 10140
[09-02-04 17:48:33.1183] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:00:5d:ff:ff:fe, will retry in 9720
[09-02-04 17:59:44.9607] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:00:5d:ff:ff:fe, will retry in 9750
[09-02-04 17:59:44.9663] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:04:20:10:0d:88, will retry in 10170
[09-02-04 17:59:56.8964] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:04:20:10:0d:88, will retry in 10200
[09-02-04 18:02:17.9634] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:00:5d:ff:ff:fe, will retry in 9780
[09-02-04 18:03:23.2938] Slim::Networking::SqueezeNetwork::PrefSync::_syncDown_error (359) Sync Down failed: No such player: 00:04:20:10:0d:88, will retry in 10230
[09-02-04 18:05:26.3761] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:00:5d:ff:ff:fe
[09-02-04 18:05:26.3978] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:04:20:10:0d:88
[09-02-04 18:06:13.1735] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:00:5d:ff:ff:fe
[09-02-04 18:06:13.1848] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:04:20:10:0d:88
[09-02-04 18:11:51.2820] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:00:5d:ff:ff:fe
[09-02-04 18:14:34.8528] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:00:5d:ff:ff:fe
Comment 1 James Richardson 2009-02-04 15:27:05 UTC
Alan: your thoughts on this one?

Andre: What stream do you start when you see this error?  Does it happen if you play local music content as well?
Comment 2 andre strebel 2009-02-04 15:51:11 UTC
i play local stream, losless sound files.
Comment 3 James Richardson 2009-02-04 20:54:07 UTC
(In reply to comment #2)
> i play local stream, losless sound files.
> 

What format?
Comment 4 Alan Young 2009-02-04 23:48:29 UTC
7 players might be beginning to push the limits of synchronization. How powerful is the server? How are the players connected (wired or wireless)?

You could try increasing the syncStartDelay preference (Settings / Networking / Synchronized Players Startup Delay (ms)) to something like 2000 or even 3500. This would give the network the chance to recover from packet loss during the period of congested network transmission at the start of a track.  This should only really affect the first track. Also, if you use crossfade, you may need to reduce the crossfade duration (for each player), perhaps to 5s.
Comment 5 James Richardson 2009-02-09 09:13:54 UTC
Andre:

Can I get more data from you please:

What are the specifications on the system that is running SqueezeCenter

File Format of the music you are streaming

Bit Rate of the music you are streaming

Is the music located on the Same system the server is running on

Is the music located on a remote location (NAS / another system / USB Drive)

What is the connection type do the various players (Wireless / Wired)

What Router are you using (Make/Model and FW Version)

Can you please test with different Numbers of players sync'd.  When does it start to fail?  I.E. 2 players OK, 4 players FAIL

Please provide a log with the following LOGS set to DEBUG:
player.sync
player.streaming
player.source
Comment 6 Alan Young 2009-02-09 09:23:03 UTC
Please add network.protocol.slimproto at level INFO to that list of logging options. Note: that lot will be quite verbose. You probably do not want to let it run for an extended period with them enabled: just long enough to capture the symptoms of your problem.
Comment 7 James Richardson 2009-02-19 08:24:25 UTC
Andre: have you had a chance to capture the data requested yet?
Comment 8 andre strebel 2009-02-19 09:11:20 UTC
this is the status:
i have removed two players and have only 5 in sync. sync with transporter is a problem too, see log:
[09-02-19 17:34:10.2931] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:35:45.7506] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:04:20:10:0d:88
[09-02-19 17:37:34.0584] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:37:34.0919] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:37:34.2287] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:37:34.2489] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:37:34.2964] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:37:34.3358] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:37:35.2926] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:37:35.3223] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:38:03.8590] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:38:03.9145] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:38:03.9742] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:38:04.0074] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:38:04.1277] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:38:06.9925] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:38:12.4390] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:04:20:10:0d:88
[09-02-19 17:40:07.3298] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:04:20:10:0d:88
[09-02-19 17:41:54.7264] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:36.9834] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:37.1046] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:43.4489] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:43.7106] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:43.7124] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:44.1690] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:45.0715] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:45.3110] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:49.2583] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:49.5215] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:49.5772] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:49.8473] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:51.8791] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:51.9383] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:52.1192] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:52.4107] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:42:52.4959] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:47:06.2706] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:04:20:10:0d:88
[09-02-19 17:47:36.1159] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:47:57.7374] Slim::Networking::SqueezeNetwork::PrefSync::_syncUp_error (576) Sync Up failed: No such player: 00:04:20:10:0d:88
[09-02-19 17:51:06.8536] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:51:06.9375] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:55:06.9220] Slim::Web::JSONRPC::requestMethod (383) request not dispatchable!
[09-02-19 17:55:07.0012] Slim::Web::JSONRPC::requestMetho
Comment 9 Alan Young 2009-02-22 01:29:04 UTC
Andre, those messages are not relevant to player synchronization. They relate to synchronization of preferences between SqueezeCentre and SqueezeNetwork.

You need to capture a log with the levels requested: see comments 5 and 6.
Comment 10 Alan Young 2009-06-09 02:36:27 UTC
Addre, are you able to supply the request logs?
Comment 11 James Richardson 2009-09-15 18:34:21 UTC
QA to verify with 7.4
Comment 12 James Richardson 2009-09-23 10:25:36 UTC
7.4 handles syncing a lot better, please retest with 7.4.  If you are able to still reproduce the issue, please provide the logs as requested in comment 5 and comment 6
Comment 13 James Richardson 2009-10-05 14:36:33 UTC
This bug has been marked as fixed in the 7.4.0 release version of SqueezeBox Server!
    * SqueezeCenter: 28672
    * Squeezebox 2 and 3: 130
    * Transporter: 80
    * Receiver: 65
    * Boom: 50
    * Controller: 7790
    * Radio: 7790  

Please see the Release Notes for all the details: http://wiki.slimdevices.com/index.php/Release_Notes

If you haven't already, please download and install the new version from http://www.logitechsqueezebox.com/support/download-squeezebox-server.html

If you are still experiencing this problem, feel free to reopen the bug with your new comments and we'll have another look.