Server Version#: 4.72.0
Player Hardware: Roku Ultra 4640R (has Toslink output DD+ ==> DD re-encoding)
Player Version# .latest on Roku by auto-update
AV System: Adcom GTP-860 II
Here’s the problem: Playing tracks off the Plex Server, the first quarter-second or so of the track drops out. Only on this though Plex ==> Android Phone or Windows laptop is fine
It’s as if something like the Toslink or the D/A converter turns off during “digital silence” and it takes a quarter-second to turn on again. It’s most-noticeable on tracks where we’d really rather have gapless playback but there’s always a little “tick!” at the beginning of a track.
I am having the same issue where music starts playing a quarter-second into songs (all music regardless of format). Only happens on Roku. My LG TV app and Firestick play fine.
Player HW: Roku Ultra 4800X, OS 10.5
Roku Plex app: v6.9 build 18
Server: Synology PMS v1.25.6.5577
I captured a log from the Roku. The portion where I hit play is below. It appears to be seeking the start of the file but then there are a couple warnings about ignoring position:0.
Any ideas what this means or what might be happening?
trleith - are you able to capture a log from your Roku?
2/27/2022 10:59:39.465 INFO (PlaybackMgr) Setting player control to 'play'. currentState=stopped, seekPosition=0
2/27/2022 10:59:39.466 INFO (PlaybackMgr) Attempting to seek to 0 and resume playback
2/27/2022 10:59:39.474 WARN (PlaybackMgr) AdManager::HandlePlayerPosition: ignoring position:0 state:stopped
2/27/2022 10:59:39.477 INFO (GeneralTask) Requesting GET https://192-168-1-
112.cdf36be13ce24969b4dc1868d860622f.plex.direct:32400/library/streams/49751/levels?subsample=256&XPlex-
Language=en-US
2/27/2022 10:59:39.486 WARN (PlaybackMgr) AdManager::HandlePlayerPosition: ignoring position:0 state:stopped
2/27/2022 10:59:39.488 INFO (PlaybackMgr) Player state changed to buffering (hasAd=false)
2/27/2022 10:59:39.492 INFO (PlaybackMgr) Playback started: eventType=normal sentItemStart=false
2/27/2022 10:59:39.492 INFO (PlaybackMgr) Setting playback active=true sendPlaybackEvent=true
2/27/2022 10:59:39.493 INFO (PlaybackMgr) Buffering percent=0 isUnderrun=false
This is interesting. It looks like the Plex player dumped its buffer and started over.
Anyone interested: you have to start the Plex app on the Roku before you can see the log at RokuAddress:8324)/logs. Apparently it does not persist between runs of the app.
SWITCHINGSTRATEGY: unaligned-segments
TITLE: Piano Concerto No. 23 in A - Allegro
URL: https://PlexAddress.df8aa741b4f14de188d5236865089d56.plex.direct:32400/library/parts/75/1631753829/file.mp3?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
2/28/2022 09:43:38.020 INFO (PlaybackMgr) Setting player control to 'play'. currentState=stopped, seekPosition=0
2/28/2022 09:43:38.020 INFO (PlaybackMgr) Attempting to seek to 0 and resume playback
2/28/2022 09:43:38.029 WARN (PlaybackMgr) AdManager::HandlePlayerPosition: ignoring position:0 state:stopped
2/28/2022 09:43:38.058 WARN (PlaybackMgr) AdManager::HandlePlayerPosition: ignoring position:0 state:stopped
2/28/2022 09:43:38.061 INFO (PlaybackMgr) Player state changed to buffering (hasAd=false)
2/28/2022 09:43:38.063 INFO (PlaybackMgr) Playback started: eventType=normal sentItemStart=false
2/28/2022 09:43:38.064 INFO (PlaybackMgr) Setting playback active=true sendPlaybackEvent=true
2/28/2022 09:43:38.065 INFO (PlaybackMgr) Buffering percent=0 isUnderrun=false
2/28/2022 09:43:38.069 INFO (PlaybackMgr) Buffering percent=6 isUnderrun=false
2/28/2022 09:43:38.076 INFO (PlaybackMgr) Buffering percent=13 isUnderrun=false
2/28/2022 09:43:38.079 DEBUG (GeneralTask) [IdleManager] Updating global lastRealKeyPress. lastKeyPress=209, lastRealKeyPress=801
2/28/2022 09:43:38.128 INFO (PlaybackMgr) Buffering percent=19 isUnderrun=false
2/28/2022 09:43:38.132 INFO (PlaybackMgr) Buffering percent=26 isUnderrun=false
2/28/2022 09:43:38.144 INFO (PlaybackMgr) Buffering percent=33 isUnderrun=false
2/28/2022 09:43:38.154 INFO (PlaybackMgr) Buffering percent=0 isUnderrun=false
2/28/2022 09:43:38.157 INFO (PlaybackMgr) Buffering percent=33 isUnderrun=false
2/28/2022 09:43:38.162 INFO (PlaybackMgr) Buffering percent=33 isUnderrun=false
2/28/2022 09:43:38.164 INFO (PlaybackMgr) Buffering percent=33 isUnderrun=false
2/28/2022 09:43:38.153 INFO (GeneralTask) Requesting GET https://PlexAddress.df8aa741b4f14de188d5236865089d56.plex.direct:32400/library/streams/75/levels?subsample=256&X-Plex-Language=en-US
2/28/2022 09:43:38.200 INFO (GeneralTask) Got response 200 GET https://PlexAddress.df8aa741b4f14de188d5236865089d56.plex.direct:32400/library/streams/75/levels?subsample=256&X-Plex-Language=en-US - 48ms (WaveformTransform) (text/xml;charset=utf-8)
2/28/2022 09:43:38.342 INFO (PlaybackMgr) Buffering percent=33 isUnderrun=false
2/28/2022 09:43:38.345 INFO (PlaybackMgr) Buffering percent=33 isUnderrun=false
2/28/2022 09:43:38.461 INFO (PlaybackMgr) Buffering percent=33 isUnderrun=false
2/28/2022 09:43:38.465 INFO (PlaybackMgr) Buffering percent=56 isUnderrun=false
2/28/2022 09:43:38.557 INFO (PlaybackMgr) Buffering percent=56 isUnderrun=false
2/28/2022 09:43:38.560 INFO (PlaybackMgr) Buffering percent=82 isUnderrun=false
2/28/2022 09:43:38.657 INFO (GeneralTask) Transformed (WaveformTransform) GET https://PlexAddress.df8aa741b4f14de188d5236865089d56.plex.direct:32400/library/streams/75/levels?subsample=256&X-Plex-Language=en-US - 448ms
2/28/2022 09:43:39.559 INFO (PlaybackMgr) Buffering percent=82 isUnderrun=false
2/28/2022 09:43:39.561 INFO (PlaybackMgr) Buffering percent=99 isUnderrun=false
2/28/2022 09:43:39.745 INFO (PlaybackMgr) Buffering percent=100 isUnderrun=false
2/28/2022 09:43:39.750 INFO (PlaybackMgr) Player state changed to playing (hasAd=false)
2/28/2022 09:43:39.752 DEBUG (PlaybackMgr) Reported metrics: playback:itemstart
2/28/2022 09:43:39.755 DEBUG (HomeScreen) HomeDynamicScreenViewModel::OnOriginsModified: originIds {roArray}
[0]: 03320b5cc787799fe6bc5cdab34497a4d8def3d6:::com.plexapp.plugins.library:::044e7504-4b9e-45c4-8596-68812c442997
2/28/2022 09:43:39.759 DEBUG (HomeScreen) HomeDynamicScreenViewModel::OnOriginsModified: originIds {roArray}
[0]: 03320b5cc787799fe6bc5cdab34497a4d8def3d6:::com.plexapp.plugins.library:::044e7504-4b9e-45c4-8596-68812c442997
2/28/2022 09:43:39.776 DEBUG (GeneralTask) [Metrics] Metrics::Flush: Already have permissions; processing events.
2/28/2022 09:43:39.796 DEBUG (GeneralTask) [Metrics] ProcessEvents: rawEventCount=1 allowedEventCount=1
2/28/2022 09:43:39.810 DEBUG (GeneralTask) [Metrics] ProcessEvents: Sending 1 metrics events in batches of 10
2/28/2022 09:43:39.843 DEBUG (GeneralTask) [Metrics] ProcessEvents: Sending batch of 1 metrics events
2/28/2022 09:43:39.884 INFO (GeneralTask) Requesting POST https://analytics.plex.tv/collect/event?X-Plex-Language=en-US
2/28/2022 09:43:39.922 INFO (GeneralTask) Requesting GET https://PlexAddress.df8aa741b4f14de188d5236865089d56.plex.direct:32400/:/timeline?playbackTime=0&time=0&state=playing&ratingKey=83&key=%2Flibrary%2Fmetadata%2F83&col=2&row=1&context=source%3Acontent.library&duration=650000&timeToFirstFrame=1&playQueueItemID=16087&X-Plex-Language=en-US
2/28/2022 09:43:39.942 INFO (GeneralTask) Got response 200 GET https://PlexAddress.df8aa741b4f14de188d5236865089d56.plex.direct:32400/:/timeline?playbackTime=0&time=0&state=playing&ratingKey=83&key=%2Flibrary%2Fmetadata%2F83&col=2&row=1&context=source%3Acontent.library&duration=650000&timeToFirstFrame=1&playQueueItemID=16087&X-Plex-Language=en-US - 20ms (TimelineTransform) (xml) (text/xml;charset=utf-8)
2/28/2022 09:43:39.960 INFO (GeneralTask) Transformed (TimelineTransform) GET https://PlexAddress.df8aa741b4f14de188d5236865089d56.plex.direct:32400/:/timeline?playbackTime=0&time=0&state=playing&ratingKey=83&key=%2Flibrary%2Fmetadata%2F83&col=2&row=1&context=source%3Acontent.library&duration=650000&timeToFirstFrame=1&playQueueItemID=16087&X-Plex-Language=en-US - 0ms
2/28/2022 09:43:39.994 INFO (PlaybackMgr) Updated timeline info {roAssociativeArray}
playerState: playing
2/28/2022 09:43:40.004 INFO (GeneralTask) Requesting GET https://PlexAddress.df8aa741b4f14de188d5236865089d56.plex.direct:32400/playQueues/491?excludeElements=Media%2CActor%2CCollection%2CCountry%2CDirector%2CGenre%2CLabel%2CMood%2CPart%2CProducer%2CRole%2CSimilar%2CWriter%2CPhoto&excludeFields=file%2Csummary%2Ctagline&includeRelated=1&own=1&continuous=0&X-Plex-Language=en-US
2/28/2022 09:43:40.042 INFO (GeneralTask) Got response 200 POST https://analytics.plex.tv/collect/event?X-Plex-Language=en-US - 158ms (json)
2/28/2022 09:43:40.115 INFO (GeneralTask) Got response 200 GET https://PlexAddress.df8aa741b4f14de188d5236865089d56.plex.direct:32400/playQueues/491?excludeElements=Media%2CActor%2CCollection%2CCountry%2CDirector%2CGenre%2CLabel%2CMood%2CPart%2CProducer%2CRole%2CSimilar%2CWriter%2CPhoto&excludeFields=file%2Csummary%2Ctagline&includeRelated=1&own=1&continuous=0&X-Plex-Language=en-US - 110ms (PlayQueueTransform) (text/xml;charset=utf-8)
2/28/2022 09:43:40.903 INFO (GeneralTask) Transformed (PlayQueueTransform) GET https://PlexAddress.df8aa741b4f14de188d5236865089d56.plex.direct:32400/playQueues/491?excludeElements=Media%2CActor%2CCollection%2CCountry%2CDirector%2CGenre%2CLabel%2CMood%2CPart%2CProducer%2CRole%2CSimilar%2CWriter%2CPhoto&excludeFields=file%2Csummary%2Ctagline&includeRelated=1&own=1&continuous=0&X-Plex-Language=en-US - 775ms
2/28/2022 09:43:46.905 DEBUG (GeneralTask) [WebServer::Server::Connection] Accepted connection @RokuAddress:56552
