[SlimDevices: SqueezeCenter] Problem playing flac files on Slimp3 (but only when sync'ed)

[InTheBath]

I have added an "Old School" Slimp3 to my very stable setup.

LMS is on a Pi and the Slimp3 and the Duet are wired to it.

Slimp3 will play all tracks consistently when not synced. As will the
Duet.
When sync'ed, I can play mp3s with no problem, but flac files are
troublesome and usually don't play. (I'm only saying usually as I think
a couple of times I've skipped forwards or back and a flac has
successfully started. 95%+ unplayable.)
BBC iPlayer is also rock solid (whether sync'ed or not).

Would love to some steer as to what to investigate!



Logitech Media Server Version: 7.9.2 - 1542403700 @ Fri Nov 16 22:48:30
CET 2018
Operating system: Debian - EN - utf8
Platform Architecture: armv7l-linux
Perl Version: 5.20.2 - arm-linux-gnueabihf-thread-multi-64int
Audio::Scan: 0.95

Player Model: Squeezebox Receiver
Firmware: 77

Old Skool
Player Model: SLIMP3
Firmware: 2.2


------------------------------------------------------------------------
InTheBath's Profile: http://forums.slimdevices.com/member.php?userid=15679
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[bpa]

Post by InTheBath
I have added an "Old School" Slimp3 to my very stable setup.
LMS is on a Pi and the Slimp3 and the Duet are wired to it.
Slimp3 will play all tracks consistently when not synced. As will the
Duet.
When sync'ed, I can play mp3s with no problem, but flac files are
troublesome and usually don't play. (I'm only saying usually as I think
a couple of times I've skipped forwards or back and a flac has
successfully started. 95%+ unplayable.)
BBC iPlayer is also rock solid (whether sync'ed or not).
Would love to some steer as to what to investigate!

Check the server.log for message ?

SliMP3 can only play MP3 so Flac has to be transcoded to MP3. When
players are synced everything is trancoded into MP3. SliMP3 has a tiny
buffer so what MP3 bitrate are you transcoding to ? what type of server
and network - you'll need a good network and server to make sure no
delays keeping SliMP3 buffer full..


------------------------------------------------------------------------
bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[InTheBath]

Thanks for the quick reply. I'll post the log at the bottom of this
message.

I understood that there was going to be some transcoding. When
everything is sync'ed, is LMS still sending flac to the newer players,
or does it transcode and send mp3 to everything?

Bitrate was 320. Have changed this to 64 and restarted the server. No
change. Like I say, everything fine on the Slimp3 when not sync'ed.
Would the buffer be affected differently when sync'ed?

Server is a 1Gb Pi2 Model B. Network is wired, but nothing fancy.
"Normal" network cables? I'm not sure exactly what info would help
here?
As I said, Slimp3 plays fine when unsync'ed (and I can play the other
squeezeboxes in a separate group whilst the Slimp3 is playing it's own
stuff, so I'm thinking the network is ok.

I really appreciate the quick response. Hope I'm helping at my end!




2018-11-24 16:20:49 squeezeboxserver_safe started.
[18-11-24 16:20:56.5888] main::init (387) Starting Logitech Media Server
(v7.9.2, 1542403700, Fri Nov 16 22:48:30 CET 2018) perl 5.020002 -
arm-linux-gnueabihf-thread-multi-64int
[18-11-24 16:21:05.6996]
Plugins::Spotty::Connect::DaemonManager::checkAPIConnectPlayers (210)
Connect daemon is running, but not connected - shutting down to force
restart: 00:04:20:16:e7:63
[18-11-24 17:48:15.7479] Slim::Networking::IO::Select::__ANON__ (131)
Error: Select task failed calling
Slim::Networking::Slimproto::client_readable: Can't locate object method
"logBacktrace" via package "Log::Log4perl::Logger" at
/usr/share/perl5/Slim/Networking/SliMP3/Stream.pm line 245.
; fh=IO::Socket::INET=GLOB(0x3807d10)
[18-11-24 18:19:16.5994] Plugins::BBCiPlayer::DASH::__ANON__ (779) Chunk
fetch status 200 Long chunk fetch time 2260 1000
[18-11-24 18:19:47.5789] Slim::Display::Lib::Fonts::__ANON__ (85)
Warning: Unable to load TrueType font support: Can't locate loadable
object for module Font::FreeType in @INC (@INC contains:
/var/lib/squeezeboxserver/cache/InstalledPlugins
/var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/BBCiPlayer/lib
/var/lib/squeezeboxserver/cache/InstalledPlugins
/usr/share/squeezeboxserver/CPAN/arch/5.20/arm-linux-gnueabihf-thread-multi-64int
/usr/share/squeezeboxserver/CPAN/arch/5.20/arm-linux-gnueabihf-thread-multi-64int/auto
/usr/share/squeezeboxserver/CPAN/arch/5.20.2/arm-linux-gnueabihf-thread-multi-64int
/usr/share/squeezeboxserver/CPAN/arch/5.20.2/arm-linux-gnueabihf-thread-multi-64int/auto
/usr/share/squeezeboxserver/CPAN/arch/arm-linux-gnueabihf-thread-multi-64int
/usr/share/squeezeboxserver/CPAN/arch/5.20
/usr/share/squeezeboxserver/lib /usr/share/squeezeboxserver/CPAN
/usr/share/squeezeboxserver /usr/sbin /etc/perl
/usr/local/lib/arm-linux-gnueabihf/perl/5.20.2
/usr/local/share/perl/5.20.2 /usr/lib/arm-linux-gnueabihf/perl5/5.20
/usr/share/perl5 /usr/lib/arm-linux-gnueabihf/perl/5.20
/usr/share/perl/5.20 /usr/local/lib/site_perl .) at
/usr/share/perl5/Slim/Display/Lib/Fonts.pm line 84.
Compilation failed in require at
/usr/share/perl5/Slim/Display/Lib/Fonts.pm line 84.
[18-11-24 18:41:35.3202] Plugins::BBCiPlayer::DASH::__ANON__ (779) Chunk
fetch status 200 Long chunk fetch time 2262 1000


------------------------------------------------------------------------
InTheBath's Profile: http://forums.slimdevices.com/member.php?userid=15679
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[bpa]

Post by InTheBath
Thanks for the quick reply. I'll post the log at the bottom of this
message.
I understood that there was going to be some transcoding. When
everything is sync'ed, is LMS still sending flac to the newer players,
or does it transcode and send mp3 to everything?
Bitrate was 320. Have changed this to 64 and restarted the server. No
change. Like I say, everything fine on the Slimp3 when not sync'ed.
Would the buffer be affected differently when sync'ed?
Server is a 1Gb Pi2 Model B. Network is wired, but nothing fancy.
"Normal" network cables? I'm not sure exactly what info would help
here?
As I said, Slimp3 plays fine when unsync'ed (and I can play the other
squeezeboxes in a separate group whilst the Slimp3 is playing it's own
stuff, so I'm thinking the network is ok.
I really appreciate the quick response. Hope I'm helping at my end!

SliMP3 buffer is tiny so when it runs out - it has to be replenished
quickly otherwise everything will stop. Syncing 2 players - means
double the amount of traffic to be sent in the same time, 3 player
triple etc.
"Feels" like transcoding could be difficult to accomplish when trying to
keep a SliMP3 happy. Pi2 may be part of the part of the problem.

Lower bitrate may mean more processing to compress but less data to send
- a compromise - not sure what is most important.


------------------------------------------------------------------------
bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[InTheBath]

Thanks. If it is bitrate then, having tried 320 and 64 (the highest and
lowest values) it looks like I'm out of luck.

I could replace the Slimp3 with a Classic - I like the look of the old
version on my desk though...


------------------------------------------------------------------------
InTheBath's Profile: http://forums.slimdevices.com/member.php?userid=15679
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[bpa]

Post by InTheBath
Thanks. If it is bitrate then, having tried 320 and 64 (the highest and
lowest values) it looks like I'm out of luck.
I could replace the Slimp3 with a Classic - I like the look of the old
version on my desk though...
Edit: just tried playing the same song on all players. If the non-Slimp3
players are in a separate group, everything works fine (the Slimp3 is
out of sync of course). If everything is in one group, the web interface
looks like its playing, but everything is silent). Could this still be a
transcoding issue?

Syncing a mixed group with SliMP3 has always been problematic - you may
get lucky and solve it but there have been many cases of failure.

You could enable some logging to find the cause. player.source will
show what transcodiing is happening but perhaps look at Pi CPU usage
first. If sync is the problem then enabling player.sync logging may
show up problems in this arera.


------------------------------------------------------------------------
bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[bpa]

Thought a bit more about this overnight.

Since BBCiPlayer sync OK and flac files don't - the issue seems to be
processor related.

For live BBCiPlayer streams are delivered in 6 secs chunk - so processor
runs faad/lame to convert a 6 sec chunk which is then ready to send out-
processor then waits for next 6 sec chunk to arrive so has time to deal
with SLimp3.
Flac files will be process by flac and lame but processor will try to
process whole source flac file (e.g. 3 minutes long) in one go and so
processor will be very intensively used for a longer peiod compared to
the 6 sec chunk of BBCiPlayer.

I wonder whether changing the LMS default transcode chain of 2 processes
Flac and Lame and pipes - to a single ffmpeg process might be easier on
the processor.

Do you have (or can install) ffmpeg (aka avconv) on your system which
has LMS ?

For completeness - please confirm sync is OK for both BBCiPLayer live
and On-demand ?


------------------------------------------------------------------------
bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[InTheBath]

You're going to hate me, and I don't know why this has happened, but
symptoms are different today!

Can't get anything to play with the players synced.
They all look like they're playing, on the web interface, the Slimp3
player (displaying a time remaining progress bar that ticks down) and
the controller. Flac and mp3 similar (although the mp3 took longer to
get going).
BBC live and on demand: Slimp3 goes quickly through "Connecting..." and
"Buffering" and sticks at "Waiting to sync..."

I am puzzled. What has changed? I've restarted the server a few times. I
changed the players "Minimum Synchronisation Adjustment" from 10ms to
202ms and now back again. I've given the server a higher priority (using
the Advanced tab of the LMS web interface) and the scanner a slightly
lower priority.

The Pi is just used as a music server, so I don't think anything
significant should have happened overnight.

Just to reiterate. I appreciate your help a lot and am still convinced I
tested well yesterday and saw the symptoms previously described. But
having some experience in user support, if I was you, I wouldn't believe
me...


------------------------------------------------------------------------
InTheBath's Profile: http://forums.slimdevices.com/member.php?userid=15679
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[bpa]

Post by InTheBath
You're going to hate me, and I don't know why this has happened, but
symptoms are different today!

Was the system rebooted ?
Is your music in a SD card or a hard disk ?

Post by InTheBath
Edit: apt-get of ffmpeg or avconv unsuccessful on pi. ffmpeg is
unavailable but referred to by another package. Avconv is "unable to
locate".

What distro are you using ?
ffmpeg or avconv is available for raspbian and many of the "mainline" Pi
distros

But it would be better to test with sox as it should be on your system
as part of LMS unless you have a custom LMS distro (how did you install
LMS? )


------------------------------------------------------------------------
bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[InTheBath]

You're a very patient person! Thanks.

Pi wasn't rebooted. Music is on a permanently mounted hard drive. About
900 albums. But the server was rebooted a few times (I tend to do it
when I fiddle with settings).

Apparently I'm running Raspbian GNU/Linux, Version 8 (Jessie).
Pi is headless and really doesn't need to do anything except run LMS.

Installation of LMS was via an apt-get: version number ius above but
it's a recent nightly build (since a recent bug about changing volume on
synced players affected me.


------------------------------------------------------------------------
InTheBath's Profile: http://forums.slimdevices.com/member.php?userid=15679
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[bpa]

Post by InTheBath
You're a very patient person! Thanks.
Pi wasn't rebooted. Music is on a permanently mounted hard drive. About
900 albums. But LMS was restarted a few times (I tend to do it when I
fiddle with settings).
Apparently I'm running Raspbian GNU/Linux, Version 8 (Jessie).
Pi is headless and really doesn't need to do anything except run LMS.
Installation of LMS was via an apt-get: version number ius above but
it's a recent nightly build (since a recent bug about changing volume on
synced players affected me.

OK. There is a copy of avaconv available for raspbian Jessie but from a
3rd party site

Without consistent symptoms, it is not worthwhile trying "solutions" as
it will not be clear if the "solution" has had good/bad effect.

I suspect your system was caching a lot of disk stuff (e.g. flac, lame,
audio files, directories) in RAM and overnight these caches have
expired/cleared out and so now some activities are taking longer. This
could indicate that your system is at the edge of being able to support
a synced SliMP3. Your previous log also showed some very long
BBCiPlayer network fetches - so perhaps you also have some ISP issues
into the mix (i.e. don't use network streams as a basis for tests)


------------------------------------------------------------------------
bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[InTheBath]

Thanks.

When playing synced all is silent and turning the Slimp3 off almost
immediately starts the audio on the other players (but not from the
beginning of the song, from what looks like the current position on all
the players).

Have swapped the Slimp3 out for a classic for a bit, but that Slimp3
sure does look sweet...


------------------------------------------------------------------------
InTheBath's Profile: http://forums.slimdevices.com/member.php?userid=15679
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[bpa]

Post by InTheBath
Thanks.
When playing synced all is silent and turning the Slimp3 off almost
immediately starts the audio on the other players (but not from the
beginning of the song, from what looks like the current position on all
the players).
Have swapped the Slimp3 out for a classic for a bit, but that Slimp3
sure does look sweet...

Enable player.sync logging to get a better idea of what is happening
with slimp3 to prevent syncing/playing.

Also the order in which you create a sync group can affect behaviour.
Try SliMP3 as the first ("master") player in a group. Sync players into
a group before starting to play anyhting.


------------------------------------------------------------------------
bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[InTheBath]

Have enabled logging at debug level on the sync. Unsynced all the
players. Turned all the players off. Plugged the Slimp3 back in and
played a flac file.
Stopped the Slimp3 and set up a group with the Slimp3 and one other
player. Tried to play a flac file.

Log is below.


(Have I told you yet how much I appreciate the help?)


[18-11-25 14:31:55.3261]
Plugins::Spotty::Connect::DaemonManager::checkAPIConnectPlayers (210)
Connect daemon is running, but not connected - shutting down to force
restart: 00:04:20:16:e7:63
[18-11-25 16:06:21.0618] Slim::Player::StreamingController::unsync
(1935) 00:04:20:04:03:51 unsync 00:04:20:16:e7:63
[18-11-25 16:06:21.0713] Slim::Player::StreamingController::unsync
(1989) 00:04:20:04:03:51 sync group now has:
00:04:20:1f:1d:b5,00:04:20:04:03:51,00:04:20:12:73:28
[18-11-25 16:06:21.0732] Slim::Player::StreamingController::unsync
(1990) 00:04:20:04:03:51 active players are: 00:04:20:04:03:51
[18-11-25 16:06:23.1113] Slim::Player::Sync::syncname (51) syncname for
00:04:20:04:03:51 is Old Skool & Kitchen Sink & Study
[18-11-25 16:06:30.5503] Slim::Player::StreamingController::unsync
(1935) 00:04:20:04:03:51 unsync 00:04:20:04:03:51
[18-11-25 16:06:30.5616] Slim::Player::StreamingController::unsync
(1989) 00:04:20:1f:1d:b5 sync group now has:
00:04:20:1f:1d:b5,00:04:20:12:73:28
[18-11-25 16:06:30.5635] Slim::Player::StreamingController::unsync
(1990) 00:04:20:1f:1d:b5 active players are:
[18-11-25 16:06:33.2559]
Plugins::Spotty::Connect::DaemonManager::checkAPIConnectPlayers (210)
Connect daemon is running, but not connected - shutting down to force
restart: 00:04:20:04:03:51
[18-11-25 16:06:40.5260] Slim::Player::StreamingController::unsync
(1935) 00:04:20:1f:1d:b5 unsync 00:04:20:1f:1d:b5
[18-11-25 16:06:40.5361] Slim::Player::StreamingController::unsync
(1989) 00:04:20:12:73:28 sync group now has: 00:04:20:12:73:28
[18-11-25 16:06:40.5380] Slim::Player::StreamingController::unsync
(1990) 00:04:20:12:73:28 active players are:
[18-11-25 16:06:44.3956]
Plugins::Spotty::Connect::DaemonManager::checkAPIConnectPlayers (210)
Connect daemon is running, but not connected - shutting down to force
restart: 00:04:20:04:03:51
[18-11-25 16:07:39.0034] Slim::Player::Player::trackJiffiesEpoch (928)
00:04:20:16:e7:63 adjust jiffies epoch -0.001s
[18-11-25 16:08:00.5978] Slim::Player::StreamingController::sync (1871)
00:04:20:04:03:51 adding to syncGroup: 00:04:20:16:e7:63
[18-11-25 16:08:00.6373] Slim::Player::StreamingController::sync (1914)
New player inactive: power=0, connected=1
[18-11-25 16:08:00.6400] Slim::Player::StreamingController::sync (1923)
00:04:20:04:03:51 sync group now has:
00:04:20:04:03:51,00:04:20:16:e7:63
[18-11-25 16:08:00.6418] Slim::Player::StreamingController::sync (1924)
00:04:20:04:03:51 active players are: 00:04:20:04:03:51
[18-11-25 16:08:02.6637] Slim::Player::Sync::syncname (51) syncname for
00:04:20:04:03:51 is Old Skool & Kitchen Sofa
[18-11-25 16:08:03.4382]
Plugins::Spotty::Connect::DaemonManager::checkAPIConnectPlayers (210)
Connect daemon is running, but not connected - shutting down to force
restart: 00:04:20:04:03:51
[18-11-25 16:08:15.4616] Slim::Player::StreamingController::playerActive
(2028) 00:04:20:04:03:51 sync group now has:
00:04:20:04:03:51,00:04:20:16:e7:63
[18-11-25 16:08:15.4636] Slim::Player::StreamingController::playerActive
(2029) 00:04:20:04:03:51 active players are:
00:04:20:04:03:51,00:04:20:16:e7:63
[18-11-25 16:08:24.0074] Slim::Player::Player::trackJiffiesEpoch (955)
00:04:20:06:30:62 adjust jiffies epoch +0.001s
[18-11-25 16:09:02.6926] Slim::Player::Sync::syncname (51) syncname for
00:04:20:04:03:51 is Old Skool & Kitchen Sofa


------------------------------------------------------------------------
InTheBath's Profile: http://forums.slimdevices.com/member.php?userid=15679
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[bpa]

Post by InTheBath
Have enabled logging at debug level on the sync. Unsynced all the
players. Turned all the players off. Plugged the Slimp3 back in and
played a flac file.
Stopped the Slimp3 and set up a group with the Slimp3 and one other
player. Tried to play a flac file.

There is no indication that playing has even started. You need to
enable player.source to INFO to see if playing is being setup.


------------------------------------------------------------------------
bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[InTheBath]

Hope this is a more useful log.



[18-12-01 17:49:38.8735] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686432.566, 00:04:20:1f:1d:b5:
+2
[18-12-01 17:49:39.8735] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686432.566, 00:04:20:1f:1d:b5:
+2

… snip …

[18-12-01 17:49:54.8729] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686432.565, 00:04:20:1f:1d:b5:
+3
[18-12-01 17:49:55.8749] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686432.565, 00:04:20:1f:1d:b5:
+3
[18-12-01 17:49:56.8730] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+204
[18-12-01 17:49:56.9248] Slim::Player::StreamingController::_CheckSync
(559) 00:04:20:1f:1d:b5 resync: skipAhead 204ms
[18-12-01 17:49:58.8725] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:49:59.8727] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:50:00.8726] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0

… snip …

[18-12-01 17:50:16.8731] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:50:17.8734] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:50:18.0076] Slim::Player::Player::trackJiffiesEpoch (955)
00:04:20:12:73:28 adjust jiffies epoch +0.001s
[18-12-01 17:50:18.8730] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:50:19.8730] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0

… snip …

[18-12-01 17:50:41.8727] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:50:42.8732] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:50:43.0092] Slim::Player::Player::trackJiffiesEpoch (955)
00:04:20:12:73:28 adjust jiffies epoch +0.001s
[18-12-01 17:50:43.8726] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:50:44.8728] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:50:45.8725] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:50:46.8729] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+1
[18-12-01 17:50:47.8726] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:50:48.8717] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0
[18-12-01 17:50:49.8728] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.925, 00:04:20:1f:1d:b5:
+0

… snip 30 lines …

[18-12-01 17:51:22.8722] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.924, 00:04:20:1f:1d:b5:
+1
[18-12-01 17:51:23.8726] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543686595.924, 00:04:20:1f:1d:b5:
+1
[18-12-01 17:53:08.0087] Slim::Player::Player::trackJiffiesEpoch (955)
00:04:20:12:73:28 adjust jiffies epoch +0.001s
[18-12-01 17:53:33.0095] Slim::Player::Player::trackJiffiesEpoch (955)
00:04:20:12:73:28 adjust jiffies epoch +0.001s

...snip several identical lines...

[18-12-01 19:48:43.0070] Slim::Player::Player::trackJiffiesEpoch (955)
00:04:20:12:73:28 adjust jiffies epoch +0.001s
[18-12-01 19:49:08.0065] Slim::Player::Player::trackJiffiesEpoch (955)
00:04:20:12:73:28 adjust jiffies epoch +0.001s
[18-12-01 19:49:37.8704] Slim::Player::Squeezebox2::startAt (1078)
00:04:20:16:e7:63 startAt: 2445972032
[18-12-01 19:49:37.8730] Slim::Player::Squeezebox2::startAt (1078)
00:04:20:1f:1d:b5 startAt: 212054151
[18-12-01 19:49:37.9014] Slim::Player::StreamingController::_CheckSync
(498) 00:04:20:16:e7:63 bailing as no playPoint
[18-12-01 19:49:39.4448] Slim::Player::StreamingController::playerActive
(2028) 00:04:20:16:e7:63 sync group now has:
00:04:20:16:e7:63,00:04:20:1f:1d:b5,00:04:20:12:73:28
[18-12-01 19:49:39.4467] Slim::Player::StreamingController::playerActive
(2029) 00:04:20:16:e7:63 active players are:
00:04:20:16:e7:63,00:04:20:1f:1d:b5,00:04:20:12:73:28
[18-12-01 19:49:39.4484] Slim::Player::StreamingController::playerActive
(2033) 00:04:20:16:e7:63 restart play
[18-12-01 19:49:41.1677] Slim::Player::Squeezebox2::startAt (1078)
00:04:20:16:e7:63 startAt: 2445975330
[18-12-01 19:49:41.1705] Slim::Player::Squeezebox2::startAt (1078)
00:04:20:1f:1d:b5 startAt: 212057448
[18-12-01 19:49:41.1724] Slim::Player::Squeezebox2::startAt (1078)
00:04:20:12:73:28 startAt: 528144429
[18-12-01 19:49:41.1896] Slim::Player::StreamingController::_CheckSync
(498) 00:04:20:16:e7:63 bailing as no playPoint
[18-12-01 19:49:42.7866] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543693781.365, 00:04:20:1f:1d:b5:
+0, 00:04:20:12:73:28: +2
[18-12-01 19:49:43.7855] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543693781.366, 00:04:20:1f:1d:b5:
-1, 00:04:20:12:73:28: +1
[18-12-01 19:49:44.7891] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543693781.366, 00:04:20:1f:1d:b5:
+0, 00:04:20:12:73:28: +0
[18-12-01 19:49:45.7856] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543693781.366, 00:04:20:1f:1d:b5:
+0, 00:04:20:12:73:28: +1
[18-12-01 19:49:46.7863] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543693781.365, 00:04:20:1f:1d:b5:
+0, 00:04:20:12:73:28: +2
[18-12-01 19:49:47.7889] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543693781.366, 00:04:20:1f:1d:b5:
+0, 00:04:20:12:73:28: +0
[18-12-01 19:49:48.7856] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543693781.366, 00:04:20:1f:1d:b5:
+0, 00:04:20:12:73:28: +0
[18-12-01 19:49:49.7856] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543693781.366, 00:04:20:1f:1d:b5:
-1, 00:04:20:12:73:28: +1
[18-12-01 19:49:50.1688]
Slim::Player::StreamingController::playerInactive (2071)
00:04:20:16:e7:63 sync group now has:
00:04:20:16:e7:63,00:04:20:1f:1d:b5,00:04:20:12:73:28
[18-12-01 19:49:50.1702]
Slim::Player::StreamingController::playerInactive (2072)
00:04:20:16:e7:63 active players are:
00:04:20:16:e7:63,00:04:20:12:73:28
[18-12-01 19:49:50.7907] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543693781.365, 00:04:20:12:73:28:
+1
[18-12-01 19:49:51.7850] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543693781.365, 00:04:20:12:73:28:
+1
[18-12-01 19:49:52.7858] Slim::Player::StreamingController::_CheckSync
(526) playPoints: 00:04:20:16:e7:63: 1543693781.365, 00:04:20:12:73:28:
+2
[18-12-01 19:49:53.0959]
Slim::Player::StreamingController::playerInactive (2071)
00:04:20:12:73:28 sync group now has:
00:04:20:16:e7:63,00:04:20:1f:1d:b5,00:04:20:12:73:28
[18-12-01 19:49:53.1250]
Slim::Player::StreamingController::playerInactive (2072)
00:04:20:12:73:28 active players are: 00:04:20:12:73:28
2018-12-01 19:52:11 squeezeboxserver_safe stopped.
2018-12-01 19:52:11 squeezeboxserver_safe started.
[18-12-01 19:52:24.9034] main::init (387) Starting Logitech Media Server
(v7.9.2, 1542403700, Fri Nov 16 22:48:30 CET 2018) perl 5.020002 -
arm-linux-gnueabihf-thread-multi-64int
[18-12-01 19:53:20.5766] Slim::Networking::Repositories::__ANON__ (146)
Failed to fetch
http://downloads.sourceforge.net/project/bpaplugins/betarelease-repo.xml:
Error reading headers: Server closed connection without sending any data
back at /usr/share/squeezeboxserver/CPAN/Net/HTTP/Methods.pm line 306.
[18-12-01 19:53:22.3147] Plugins::Spotty::API::_gotTokenResponse (179)
Failed to get Spotify access token: 'true' expected, at character offset
0 (before "thread 'main' panick...") at
/var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/Spotty/API.pm
line 176.

thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value:
Error { repr: Os { code: 2, message: "No such file or directory" } }',
/checkout/src/libcore/result.rs:916:5
note: Run with `RUST_BACKTRACE=1` for a backtrace.
Aborted
[18-12-01 19:53:22.3167] Plugins::Spotty::API::_gotTokenResponse (194)
Failed to get Spotify access token
[18-12-01 19:55:17.9099] Slim::Menu::TrackInfo::__ANON__ (270) TrackInfo
menu item "DashLiveRew" failed: Can't call method "streamformat" on an
undefined value at
/var/lib/squeezeboxserver/cache/InstalledPlugins/Plugins/BBCiPlayer/Plugin.pm
line 271.


------------------------------------------------------------------------
InTheBath's Profile: http://forums.slimdevices.com/member.php?userid=15679
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[bpa]

Post by InTheBath
Hope this is a more useful log.

log extract are what you find interesting - but you may be editing
things somnetimes what is missing is most important - why not just zip a
text file containg the logs from the log file between the times you are
testing and attach thelog file.

A log without a description is not great - you have not said anything
about what is being tested and how ti is being tested - how many
players and types ,what type of file isbeing played, what time stream
started, what happened when playing and at what time ?

The "bailing" indicates that sync has failed.


------------------------------------------------------------------------
bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[InTheBath]

Thanks, I'll do that later. I really struggled to post anything within
the character limits. Will investigate how to add a text file.


------------------------------------------------------------------------
InTheBath's Profile: http://forums.slimdevices.com/member.php?userid=15679
View this thread: http://forums.slimdevices.com/showthread.php?t=109799

[bpa]

Post by InTheBath
Thanks, I'll do that later. I really struggled to post anything within
the character limits. Will investigate how to add a text file.

A text file can be zipped into very small - so an extract of the log
file zipped will easily fit the limits. Make sure extension is ".zip"
as there are restrictions on file extensions can be attached.

To attach use the "manage Attachements" button when creating the post -
in the manage attachement click on the "add files" button in top right
of popup and then "choose file".


------------------------------------------------------------------------
bpa's Profile: http://forums.slimdevices.com/member.php?userid=1806
View this thread: http://forums.slimdevices.com/showthread.php?t=109799