Bugzilla – Bug 16240
Internet radio synchronization no longer shares streams
Last modified: 2010-05-25 10:54:16 UTC
I have a premium account with sky.fm, and have multiple Boom's in my house. I have them all set to be synchronized. With version 7.4.2, I was able to play the same (128k AAC stream) premium sky.fm station on them all with no problems. After upgrading to 7.5.0, I am only able to play on one boom at a time - the other ones shut off. After this started happening, I received a warning email from sky.fm informing me I was connecting multiple times (they allow only one premium connection at a time), so this confirmed to me that the booms are somehow not reusing the same stream now. At first, I wasn't sure if I was lucky before or stream reuse was the default, but after seeing the thread http://forums.slimdevices.com/showthread.php?t=64825 I think this is a regression.
That sounds very odd. Can you confirm that you are using Squeezebox Server and not mysqueezebox.com? If this is the case then can you enable logging (from the WebUI: Setings / Advanced / Logging) and set player.source to INFO level. Attach a copy of the resulting logfile when you play the station with a couple of synced players.
Created attachment 6863 [details] server.log file
Okay, I've tried to duplicate the behavior with logging enabled. I have synchronization set up between 2 Booms and 1 Squeezebox2. At first everything worked, so I tried switching stations between the various rooms. Finally at around 14:14, switching to the sky.fm station failed - music stopped playing on all three devices. At one point it output some garbage sound and then went completely silent. I don't understand the logs, so I'm hoping this may be related or the same problem. Before my wife said similar things were happening, but it was playing in one room only. Strangely it looks like other stations continued working, but trying to switch back to sky.fm still played no music. I've attached the log file, with my password changed to PASSWORD. The problem URL is http://www.sky.fm/listen/newage/128k.pls?user=kevin8t8&pass=PASSWORD I hope this helps. If not, please let me know and I'll try to generate more logs.
What we see from that log i sevidence of network congestion. Here is an edited extract: [10-05-22 14:14:51.0486] Slim::Player::Player::_buffering (1149) Buffering... 18029 / 49152 [10-05-22 14:14:51.1024] Slim::Player::StreamingController::playerBufferReady (2132) 00:04:20:05:c0:74 [10-05-22 14:14:51.1028] Slim::Player::StreamingController::_setPlayingState (2231) new playing state WAITING_TO_SYNC [10-05-22 14:14:51.1034] Slim::Player::StreamingController::playerBufferReady (2132) 00:04:20:1e:63:e9 [10-05-22 14:14:51.1071] Slim::Player::StreamingController::playerBufferReady (2132) 00:04:20:1e:78:c0 [10-05-22 14:14:51.1078] Slim::Player::StreamingController::_setPlayingState (2231) new playing state PLAYING [10-05-22 14:14:51.1082] Slim::Player::StreamingController::_Playing (361) Song 0 has now started playing [10-05-22 14:14:51.1091] Slim::Player::StreamingController::_Playing (389) Song queue is now 0 [10-05-22 14:15:46.2671] Slim::Player::StreamingController::playerTrackStarted (2043) 00:04:20:1e:78:c0 [10-05-22 14:15:46.2730] Slim::Player::StreamingController::playerTrackStarted (2043) 00:04:20:1e:63:e9 [10-05-22 14:15:46.2748] Slim::Player::StreamingController::playerTrackStarted (2043) 00:04:20:05:c0:74 [10-05-22 14:15:46.4862] Slim::Player::StreamingController::playerOutputUnderrun (2082) 00:04:20:1e:63:e9: decoder: 1889 / output: 0 [10-05-22 14:15:46.4866] Slim::Player::StreamingController::_setPlayingState (2231) new playing state BUFFERING [10-05-22 14:15:46.4911] Slim::Player::StreamingController::playerOutputUnderrun (2082) 00:04:20:1e:78:c0: decoder: 1889 / output: 0 [10-05-22 14:15:46.4921] Slim::Player::StreamingController::playerOutputUnderrun (2082) 00:04:20:05:c0:74: decoder: 2419 / output: 0 [10-05-22 14:15:46.6144] Slim::Player::Player::_buffering (1149) Buffering... 1889 / 80000 [10-05-22 14:15:46.6161] Slim::Player::Player::_buffering (1149) Buffering... 2419 / 80000 This shows that the players actually started playing (playerTrackStarted) at 14:15:46, or at least that is when the server received the notification that they had started, and them immediately ran out of data (playerOutputUnderrun). There are several other occurrences of playerOutputUnderrun which tends to confirm the network congestion theory. But the most damaging evidence is the gap between when the players were told to start playing (14:14:51.1078) and when it actually reported that it started (14:15:46.2671). I suspect that your network is somehow overloaded, possibly by interference from adjacent networks. This will show up more strongly when synced, because there are multiple streams involved, or when streaming higher-bitrate channels.
One of the Booms is on wireless, but the other Boom and the Squeezebox2 are connected via ethernet. I am highly suspicious of the overloaded network theory. I live on 20 acres. There are no houses in sight distance of my house, plus that would only interfere with the wireless Boom. For the wired network, I have a Cisco Catalyst 2960G switch over cat-6 wiring. I shouldn't even be close to stressing that out. My home music library is all flac, which I routinely stream to multiple of these devices. I suppose it's always possible my switch is wigging out, but I've seen no other indications of network problems at home. That all said, the machine the squeezebox server is running on isn't anything special: it's just a Pentium 4 3.0ghz with 2GB of RAM. But it's not doing anything else, so should be okay too I think.
Your server certainly sounds good enough. With most things wired, I agree that network congestion seems less likely. Nonetheless the timestamps and delays indicated in the logging are hard to argue with. Maybe you do indeed have a problem with your router, or something odd is happening with your server's network interface.
If there is truly nothing else to investigate, then I guess you can close this bug report. The only other comment I'll make is that this started just after upgrading to 7.5.0, and it only happens during synchronization. If I play three different stations on the three devices at the same time, there are no problems. From my point of view, it looks like synchronization is somehow confusing the server. Perhaps even something to do with AAC. The 7.4.2 version of the server has disappeared off of http://debian.slimdevices.com/. If you still have a copy of that I would love to downgrade and see if I can duplicate the problem (or at least be able to turn synchronization back on).
The log you uploaded did indeed appear to show network problems. Perhaps it was not typical. If you try again to capture a log and describe when things go wrong then maybe we will get a different picture. The 7.4.2 versions can be found at http://downloads.slimdevices.com/SqueezeboxServer_v7.4.2
Okay I understand. I'll play around with things, and if I can find anything else I'll post back here. Thank you for your help and time, and also for the 7.4.2 link.