PDA

View Full Version : Syncing problems with 7.3



treble
2008-12-21, 13:52
I installed the new SqueezeCenter the other day, and not syncing between Softsqueeze and Boom and SB3 is terrible.

I was syncing perfect with 7.2 and previous versions, but now Softsqueeze is about a second or so behind. The boom and SB3 sync fine, but Softsqueeze not.

Anyone else seeing the same problems? Or has any ideas why it stopped syncing?

Below some debugging log entries...





[08-12-21 12:48:54.0215] Slim::Player::Player::trackJiffiesEpoch (927) 00:04:20:06:30:28 adjust jiffies epoch -0.002s
[08-12-21 12:48:55.0168] Slim::Player::Player::trackJiffiesEpoch (951) f0:10:1a:6c:63:6e adjust jiffies epoch +0.001s
[08-12-21 12:48:55.0178] Slim::Player::StreamingController::_CheckSync (459) playPoints: f0:10:1a:6c:63:6e: 1229892436.270, 00:04:20:06:30:28: +9, 00:04:20:1e:46:58: +9
[08-12-21 12:48:56.0179] Slim::Player::StreamingController::_CheckSync (459) playPoints: f0:10:1a:6c:63:6e: 1229892436.270, 00:04:20:06:30:28: +9, 00:04:20:1e:46:58: +9
[08-12-21 12:48:56.5304] Slim::Player::Player::trackJiffiesEpoch (927) 00:04:20:1e:46:58 adjust jiffies epoch -0.013s
[08-12-21 12:48:57.0013] Slim::Player::Player::trackJiffiesEpoch (927) f0:10:1a:6c:63:6e adjust jiffies epoch -0.012s
[08-12-21 12:48:57.0023] Slim::Player::StreamingController::_CheckSync (459) playPoints: f0:10:1a:6c:63:6e: 1229892436.269, 00:04:20:06:30:28: +10, 00:04:20:1e:46:58: -1
[08-12-21 12:48:57.0090] Slim::Player::Player::trackJiffiesEpoch (927) 00:04:20:06:30:28 adjust jiffies epoch -0.012s
[08-12-21 12:48:58.0174] Slim::Player::StreamingController::_CheckSync (459) playPoints: f0:10:1a:6c:63:6e: 1229892436.267, 00:04:20:06:30:28: +0, 00:04:20:1e:46:58: +0
[08-12-21 12:48:59.0173] Slim::Player::StreamingController::_CheckSync (459) playPoints: f0:10:1a:6c:63:6e: 1229892436.266, 00:04:20:06:30:28: +0, 00:04:20:1e:46:58: +0
[08-12-21 12:49:00.0169] Slim::Player::StreamingController::_CheckSync (459) playPoints: f0:10:1a:6c:63:6e: 1229892436.264, 00:04:20:06:30:28: +2, 00:04:20:1e:46:58: +2
[08-12-21 12:49:01.0175] Slim::Player::StreamingController::_CheckSync (459) playPoints: f0:10:1a:6c:63:6e: 1229892436.263, 00:04:20:06:30:28: +3, 00:04:20:1e:46:58: +3
[08-12-21 12:49:02.0176] Slim::Player::StreamingController::_CheckSync (459) playPoints: f0:10:1a:6c:63:6e: 1229892436.260, 00:04:20:06:30:28: +7, 00:04:20:1e:46:58: +7
[08-12-21 12:49:02.8461] Slim::Player::Player::trackJiffiesEpoch (951) 00:04:20:1e:46:58 adjust jiffies epoch +0.005s
[08-12-21 12:49:03.0172] Slim::Player::StreamingController::_CheckSync (459) playPoints: f0:10:1a:6c:63:6e: 1229892436.258, 00:04:20:06:30:28: +8, 00:04:20:1e:46:58: +13
[08-12-21 12:49:04.0176] Slim::Player::StreamingController::_CheckSync (459) playPoints: f0:10:1a:6c:63:6e: 1229892436.258, 00:04:20:06:30:28: +8, 00:04:20:1e:46:58: +14


Version: 7.3 - 24282 @ Thu Dec 11 14:38:17 PST 2008
Server IP Address: 192.168.168.218
Server HTTP Port Number: 9000
Operating system: Windows XP - EN - cp1252
Platform Architecture: 586
Perl Version: 5.8.8 - MSWin32-x86-multi-thread
MySQL Version: 5.0.22-community-nt
Total Players Recognized: 3

SoftSqueeze
Player Model: softsqueeze
Firmware: 2
Player IP Address: 127.0.0.1
Player MAC Address: f0:10:1a:6c:63:6e

Squeezebox
Player Model: squeezebox3
Firmware: 120
Player IP Address: 192.168.168.215
Player MAC Address: 00:04:20:06:30:28

Squeezebox Boom
Player Model: boom
Firmware: 40
Player IP Address: 192.168.168.221
Player MAC Address: 00:04:20:1e:46:58
Wireless Signal Strength: 83%

DoomWolf
2008-12-22, 04:04
SoftSqueeze has never been able to synch properly with hardware players due to differences in software vs hardware playback. I would suggest giving the new SqueezePlay software a go instead of SoftSqueeze.

However, I'm also having huge problems with synch between my SB3 and Controller. Whatever I try, I cannot get them to synch properly at all. The playback on the Controller is always slower than that on the SB3. If a track starts off in synch, it immediately drops slightly out and by the end of a 4 minute track, the Controller playback is around 5 seconds behind that of the SB3.

This happens when playing back local MP3 files and internet radio streams. It did once attempt to resynch the two players mid-track (it even shows it in the log file), but it dropped out of synch again within a couple of seconds.

I've tried restarting both players and SqueezeCenter before synchronising them. Nothing helps. Also, if I try a few tracks, I get to a point where playback on the Controller stops entirely even though the display says it's playing back (and the SB3 is still playing fine). I then have to unsynch the players for the Controller playback to work again.

Snippets from the log:


[08-12-18 23:22:53.0238] Slim::Player::Player::trackJiffiesEpoch (951) 00:04:20:1a:9e:bf adjust jiffies epoch +0.003s
[08-12-18 23:22:54.5976] Slim::Player::StreamingController::sync (1325) 00:04:20:07:0d:bc adding to syncGroup: 00:04:20:1a:9e:bf
[08-12-18 23:22:54.5985] Slim::Player::StreamingController::sync (1372) 00:04:20:07:0d:bc sync group now has: 00:04:20:07:0d:bc,00:04:20:1a:9e:bf
[08-12-18 23:22:54.5990] Slim::Player::StreamingController::sync (1373) 00:04:20:07:0d:bc active players are: 00:04:20:07:0d:bc,00:04:20:1a:9e:bf
[08-12-18 23:22:55.0819] Slim::Player::TranscodingHelper::getConvertCommand 2 (454) Matched: mp3->mp3 via: -
[08-12-18 23:23:02.1492] Slim::Player::Player::trackJiffiesEpoch (951) 00:04:20:1a:9e:bf adjust jiffies epoch +0.004s
[08-12-18 23:23:03.0037] Slim::Player::Player::trackJiffiesEpoch (951) 00:04:20:07:0d:bc adjust jiffies epoch +0.003s
[08-12-18 23:23:03.5123] Slim::Player::StreamingController::play (1546) 00:04:20:07:0d:bc
[08-12-18 23:23:03.5138] Slim::Player::StreamingController::_Stop (532) Song queue is now 5
[08-12-18 23:23:03.5141] Slim::Player::StreamingController::_setPlayingStat e (1779) new playing state STOPPED
[08-12-18 23:23:03.5144] Slim::Player::StreamingController::_setStreamingSt ate (1792) new streaming state IDLE
[08-12-18 23:23:03.5158] Slim::Player::Song::new (64) index 5 -> file:///M:/Music/Europe/1982-1992/08%20On%20Broken%20Wings.mp3
[08-12-18 23:23:03.5163] Slim::Player::StreamingController::_setStreamingSt ate (1792) new streaming state TRACKWAIT
[08-12-18 23:23:03.5167] Slim::Player::Song::getNextSong (178) file:///M:/Music/Europe/1982-1992/08%20On%20Broken%20Wings.mp3
[08-12-18 23:23:03.5171] Slim::Player::StreamingController::_nextTrackReady (639) 00:04:20:07:0d:bc: nextTrack will be index 5
[08-12-18 23:23:03.5174] Slim::Player::StreamingController::_Stream (913) 00:04:20:07:0d:bc: preparing to stream song index 5
[08-12-18 23:23:03.5176] Slim::Player::StreamingController::_Stream (918) Song queue is now 5,5
[08-12-18 23:23:03.5180] Slim::Player::Song::open (302) file:///M:/Music/Europe/1982-1992/08%20On%20Broken%20Wings.mp3
[08-12-18 23:23:03.5195] Slim::Player::TranscodingHelper::getConvertCommand 2 (454) Matched: mp3->mp3 via: -
[08-12-18 23:23:03.5198] Slim::Player::Song::open (323) seek=false time=0 canSeek=1
[08-12-18 23:23:03.5208] Slim::Player::TranscodingHelper::getConvertCommand 2 (454) Matched: mp3->mp3 via: -
[08-12-18 23:23:03.5213] Slim::Player::Song::open (340) Transcoder: streamMode=I, streamformat=mp3
[08-12-18 23:23:03.5216] Slim::Player::Song::open (364) Opening stream (no direct streaming) using Slim::Player::Protocols::File [file:///M:/Music/Europe/1982-1992/08%20On%20Broken%20Wings.mp3]
[08-12-18 23:23:03.5226] Slim::Player::Protocols::File::open (79) duration: [223.233] size: [8929332] endian [] offset: [13747] for file:///M:/Music/Europe/1982-1992/08%20On%20Broken%20Wings.mp3
[08-12-18 23:23:03.5229] Slim::Player::Protocols::File::open (96) Opening file M:\Music\Europe\1982-1992\08 On Broken Wings.mp3
[08-12-18 23:23:03.5236] Slim::Player::Protocols::File::open (169) Seeking in 13747 into M:\Music\Europe\1982-1992\08 On Broken Wings.mp3
[08-12-18 23:23:03.5242] Slim::Player::Song::open (385) URL is a song (audio): file:///M:/Music/Europe/1982-1992/08%20On%20Broken%20Wings.mp3, type=mp3
[08-12-18 23:23:03.5302] Slim::Player::StreamingController::_Stream (956) 00:04:20:07:0d:bc: stream
[08-12-18 23:23:03.5325] Slim::Player::StreamingController::_Stream (956) 00:04:20:1a:9e:bf: stream
[08-12-18 23:23:03.5345] Slim::Player::StreamingController::_Stream (985) Song queue is now 5,5
[08-12-18 23:23:03.5350] Slim::Player::StreamingController::_setPlayingStat e (1779) new playing state BUFFERING
[08-12-18 23:23:03.5353] Slim::Player::StreamingController::_setStreamingSt ate (1792) new streaming state STREAMING
[08-12-18 23:23:03.5556] Slim::Utils::Misc::msg (1126) Warning: [23:23:03.5553] Use of uninitialized value in sysread at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Protocols/File.pm line 216.
[08-12-18 23:23:03.5567] Slim::Utils::Misc::msg (1126) Warning: [23:23:03.5564] Use of uninitialized value in sysread at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Protocols/File.pm line 216.
[08-12-18 23:23:03.5616] Slim::Player::Player::trackJiffiesEpoch (927) 00:04:20:07:0d:bc adjust jiffies epoch -0.003s
[08-12-18 23:23:03.5622] Slim::Player::StreamingController::playerBufferRea dy (1680) 00:04:20:07:0d:bc
[08-12-18 23:23:03.5625] Slim::Player::StreamingController::_setPlayingStat e (1779) new playing state WAITING_TO_SYNC
[08-12-18 23:23:03.5898] Slim::Utils::Misc::msg (1126) Warning: [23:23:03.5894] Use of uninitialized value in sysread at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Protocols/File.pm line 216.
[08-12-18 23:23:03.6065] Slim::Utils::Misc::msg (1126) Warning: [23:23:03.6062] Use of uninitialized value in sysread at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Protocols/File.pm line 216.


[08-12-18 23:23:17.0071] Slim::Player::Player::trackJiffiesEpoch (927) 00:04:20:07:0d:bc adjust jiffies epoch -0.002s
[08-12-18 23:23:17.0077] Slim::Player::StreamingController::_CheckSync (431) 00:04:20:1a:9e:bf bailing as no playPoint
[08-12-18 23:23:17.0645] Slim::Utils::Misc::msg (1126) Warning: [23:23:17.0641] Use of uninitialized value in sysread at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Protocols/File.pm line 216.
[08-12-18 23:23:17.9153] Slim::Utils::Misc::msg (1126) Warning: [23:23:17.9149] Use of uninitialized value in sysread at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Protocols/File.pm line 216.
[08-12-18 23:23:17.9426] Slim::Utils::Misc::msg (1126) Warning: [23:23:17.9423] Use of uninitialized value in numeric lt (<) at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Player.pm line 1023.
[08-12-18 23:23:18.0164] Slim::Player::StreamingController::_CheckSync (431) 00:04:20:1a:9e:bf bailing as no playPoint
[08-12-18 23:23:18.7434] Slim::Utils::Misc::msg (1126) Warning: [23:23:18.7431] Use of uninitialized value in sysread at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Protocols/File.pm line 216.
[08-12-18 23:23:18.9990] Slim::Utils::Misc::msg (1126) Warning: [23:23:18.9986] Use of uninitialized value in numeric lt (<) at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Player.pm line 1023.
[08-12-18 23:23:19.0145] Slim::Player::StreamingController::_CheckSync (431) 00:04:20:1a:9e:bf bailing as no playPoint
[08-12-18 23:23:19.5154] Slim::Utils::Misc::msg (1126) Warning: [23:23:19.5151] Use of uninitialized value in sysread at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Protocols/File.pm line 216.
[08-12-18 23:23:20.0094] Slim::Player::StreamingController::_CheckSync (431) 00:04:20:1a:9e:bf bailing as no playPoint
[08-12-18 23:23:20.0701] Slim::Utils::Misc::msg (1126) Warning: [23:23:20.0697] Use of uninitialized value in numeric lt (<) at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Player.pm line 1023.
[08-12-18 23:23:20.3584] Slim::Utils::Misc::msg (1126) Warning: [23:23:20.3581] Use of uninitialized value in sysread at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Protocols/File.pm line 216.
[08-12-18 23:23:21.0123] Slim::Player::StreamingController::_CheckSync (431) 00:04:20:1a:9e:bf bailing as no playPoint
[08-12-18 23:23:21.0333] Slim::Utils::Misc::msg (1126) Warning: [23:23:21.0330] Use of uninitialized value in numeric lt (<) at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Player.pm line 1023.
[08-12-18 23:23:21.2007] Slim::Utils::Misc::msg (1126) Warning: [23:23:21.2004] Use of uninitialized value in sysread at /<C:\Program Files\SqueezeCenter\server\squeezecenter.exe>Slim/Player/Protocols/File.pm line 216.

Version: 7.3 - 24282 @ Thu Dec 11 14:38:17 PST 2008
Hostname: stu-home-serv02
Server IP Address: 192.168.0.8
Server HTTP Port Number: 9000
Operating system: Windows Server 2003 - EN - cp1252
Platform Architecture: 586
Perl Version: 5.8.8 - MSWin32-x86-multi-thread
MySQL Version: 5.1.30-community
Total Players Recognized: 2

Controller
Player Model: controller
Player IP Address: 192.168.0.20
Player MAC Address: 00:04:20:1a:9e:bf

Lounge
Player Model: squeezebox3
Firmware: 120
Player IP Address: 192.168.0.7
Player MAC Address: 00:04:20:07:0d:bc
Wireless Signal Strength: 60%

TheRooster2000
2008-12-22, 04:30
(...) However, I'm also having huge problems with synch between my SB3 and Controller. Whatever I try, I cannot get them to synch properly at all (...)

Same here with SBC and Transporter! :(

Christian

DoomWolf
2008-12-22, 04:56
I hope this is due to the Controller playback currently only being in beta.

http://forums.slimdevices.com/showthread.php?p=364931

TheRooster2000
2008-12-22, 05:09
So do I.
Keep fingers crossed! ;)

Christian

Kuben72
2008-12-22, 10:14
It is. I read in one of the threads that it has the same problems as softsqueeze has, because right now it is "just" a software player.

treble
2008-12-22, 12:44
I know that I shouldn't expect 100% perfect sync. But it _was_ syncing perfectly before I upgraded from 7.2 to 7.3. Syncing between software and hardware players has improved a lot since Slimserver became Squeezecenter. Right now I have a second or more delay which is way too much, even for 'non-perfect' syncing.

treble
2008-12-22, 14:22
I just tried SqueezePlay. Thanks for the tip. I didn't know it was out as a Windows Executable yet. Good news, so far the syncing seems fine! I was about to downgrade again...

SqueezePlay looks nice. I wish there was an option to make the interface/window smaller though...

CatBus
2008-12-22, 15:16
Those reporting SBC/Transporter sync issues should keep an eye on this bug: http://bugs.slimdevices.com/show_bug.cgi?id=6442

DoomWolf
2008-12-22, 16:38
SqueezePlay looks nice. I wish there was an option to make the interface/window smaller though...

You can. Just resize the window as you would with any other application window. It actually goes down to a minimum size that looks the same dimensions as the Controller's screen.

treble
2008-12-22, 19:23
The resizing doesn't work on my PC then. I can make it bigger, but the smallest I can make it is about 800x600 pixels...

DoomWolf
2008-12-23, 01:35
Interesting, I've just installed SqueezePlay on my work PC and it does what you say of not resizing smaller than about 800x600. The one installed on my home PC (downloaded last week) resizes much smaller. A bug perhaps?

awy
2008-12-23, 03:31
I'm not sure why Softsqueeze syncing would have changed significantly from 7.2 to 7.3 but I guess the lack of inter-track resync could be relevant.

If SS is a constant interval off (out of sync) you could try adjusting it with the setting under Settings / Player / <player> /Synchronize. The changes should take effect pretty-much immediately. But if you enable player.sync==debug logging and constantly see a message such as 'bailing bacause no play-point' or similar then the setting above will not help.

awy
2008-12-23, 03:32
It is. I read in one of the threads that it has the same problems as softsqueeze has, because right now it is "just" a software player.

For the SBC this should not be a limitation. It is just that it does not yet work (http://forums.slimdevices.com/showthread.php?p=364931)

treble
2008-12-24, 14:04
Thanks for all the feedback. Very much appreciated.

It might indeed be a constant offset that SoftSqueeze has since upgrading to 7.3. I might play with it. But I can now 'resize' SqueezePlay as well. I didn't realize there were different skins. The default when you install is 'Desktop Skin', which is about 800x600. Then I noticed Controller Skin in the Settings, and now it has a nice small interface, actually looking like the Controller. Pretty neat! Nice work.

Thanks again!