Playback pausing when playing MKV files

Server Version#: 1.25.2.5319
Web Player Version#: 4.66.1
Roku Player Version#: 6.9.14.7448-9fa2246a1-Plex
Roku OS Version#: 10.5.0 build 4201-94
Synology OS Version#: 7.0.1-42218 (File storage)
Raspberry Pi Model#: 3B Rev 1.2
Raspberry Pi OS Version#: 10 (buster) (Updated 12/15/21)

After the last update to Plex Media Server, anytime I try to play a .mkv file, the file plays for ~2 minutes then pauses. It acts as though it’s trying to buffer, but never completes. Stopping and resuming the media continues playback for another ~ 2 minutes. Rinse and repeat ad infinitum.

I’ve played other files, .mp4 & .avi, with no issues at all.

I have restarted the plexmediaserver service as well as rebooted both the Raspberry Pi hosting the server, and the Synology NAS hosting the files, yet the issue persists.
Plex Media Server Databases_2021-12-16_10-46-44.zip (14.6 MB)
Plex Media Server Logs_2021-12-16_10-40-06.zip (3.7 MB)

2 Likes

I’ve been investigating this issue for 2 days now. I discovered it by accident yesterday while testing the latest server version on my QA server through a web browser.

Here’s what i’ve found so far…

  1. Playback goes into a spinning state in the browser and shows “Buffering” on the server dashboard and stays there infinitely until playback is forcibly stopped.
  2. The issue occurs on multiple servers/platforms. I’ve reproduced it on my win10 prod server, my win 10 QA server and my ubuntu beta server. All storage is local to the servers themselves.
  3. The issue occurs via app.plex.tv and via 127.0.0.1:32400 on Edge, Firefox and Chrome (i’ve tested all 3 on my main laptop (win 10), Firefox on another win 10 laptop and Firefox on a win 7 laptop). At first i thought it was a network problem but after i started eliminating network devices down the line and got down to testing localhost where it still occured, i eliminated that possibility. I have not tested via my other devices so far.
  4. The issue does not occur on server versions 1.18 to 1.24. The latest version i’ve tested that the issue does not occur is 1.24.5.5173. The first version the issue starts occuring for me is 1.25.0.5282 (i don’t have 5220/5246 to test). It occurs subsequently on 1.25.1.5286 and 1.25.2.5319.
  5. So far it happens on .mkv 1080p h.264 files that are video direct-streamed and with either AC3 5.1/DTS 5.1 transcoded to AAC for the browser or AAC 5.1 direct streamed. No subtitles are enabled. I’m assuming it’s not possible for mkv to be direct played?
  6. It usually happens in the first 2 mins of the movie and on high bitrate movies. I’ve reproduced it on 3 movies so far. What’s interesting it that the issue can occur on different browsers at different times. For instance, on a 11.9 Mbps movie where the issue happens consistently at 1m59s on Edge, it will happen consistently at 1m44s on Firefox.
  7. If the video is forced to transcode (either manually on the local network or automatically remotely due to bandwidth limitations) the issue does NOT occur.
  8. I have not seen the issue on mp4/avi yet, though have not tested it extensively.

EDIT: I can’t speak for the original poster, but i don’t have anything remarkable in my debug log between last the “playing” and the “buffering” activity

Dec 16, 2021 11:37:08.855 [7712] DEBUG - Request: [127.0.0.1:6646 (Loopback)] GET /:/timeline?ratingKey=7&key=%2Flibrary%2Fmetadata%2F7&playbackTime=118991&playQueueItemID=43&state=playing&hasMDE=1&context=library%3Acontent.library&row=0&col=4&time=119000&duration=6314000 (12 live) TLS GZIP Signed-in Token (MY_USER_NAME)
Dec 16, 2021 11:37:08.856 [7712] DEBUG - Client [eff8qj7ctzjj310ub14n7cgn] reporting timeline state playing, progress of 119000/6314000ms for guid=, playbackTime=118991ms ratingKey=7 url=, key=/library/metadata/7, containerKey=, metadataId=7, source=
Dec 16, 2021 11:37:08.857 [7712] DEBUG - Play progress on 7 'Star Trek III: The Search for Spock' - got played 119000 ms by account 1!
Dec 16, 2021 11:37:08.857 [7712] DEBUG - [Now] User is MY_USER_NAME (ID: 1)
Dec 16, 2021 11:37:08.857 [7712] DEBUG - [Now] Device is Microsoft Edge (Microsoft Edge).
Dec 16, 2021 11:37:08.857 [7712] DEBUG - [Now] Profile is Microsoft Edge
Dec 16, 2021 11:37:08.857 [7712] DEBUG - [Now] Updated play state for /library/metadata/7.
Dec 16, 2021 11:37:08.859 [7712] DEBUG - Statistics: (erdmngisqvsg1rtx2rgqpcf6) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Dec 16, 2021 11:37:08.864 [19416] DEBUG - Completed: [127.0.0.1:6646] 200 GET /:/timeline?ratingKey=7&key=%2Flibrary%2Fmetadata%2F7&playbackTime=118991&playQueueItemID=43&state=playing&hasMDE=1&context=library%3Acontent.library&row=0&col=4&time=119000&duration=6314000 (12 live) TLS GZIP 9ms 757 bytes (pipelined: 79)
Dec 16, 2021 11:37:09.156 [16116] DEBUG - Request: [127.0.0.1:6646 (Loopback)] GET /:/timeline?ratingKey=7&key=%2Flibrary%2Fmetadata%2F7&playbackTime=119992&playQueueItemID=43&state=buffering&hasMDE=1&context=library%3Acontent.library&row=0&col=4&time=119000&duration=6314000 (12 live) TLS GZIP Signed-in Token (MY_USER_NAME)
Dec 16, 2021 11:37:09.156 [16116] DEBUG - Client [eff8qj7ctzjj310ub14n7cgn] reporting timeline state buffering, progress of 119000/6314000ms for guid=, playbackTime=119992ms ratingKey=7 url=, key=/library/metadata/7, containerKey=, metadataId=7, source=
Dec 16, 2021 11:37:09.158 [16116] DEBUG - Play progress on 7 'Star Trek III: The Search for Spock' - got played 119000 ms by account 1!

If somebody wants to provide me links to versions 5220/5246 for windows, i can try to narrow the version down further.

1 Like

Is this one of the failing file sessions?

Dec 16, 2021 05:03:56.790 [0x70a7ed48] DEBUG - Starting a transcode session b95d65ad-a334-437c-bb1e-fd59bcd3b4bb at offset -1.0 (state=3)
Dec 16, 2021 05:03:56.790 [0x70a7ed48] DEBUG - Streaming Resource: Added session 0x704a6880:b95d65ad-a334-437c-bb1e-fd59bcd3b4bb
Dec 16, 2021 05:03:56.793 [0x70a7ed48] DEBUG - [Universal] Using local file path instead of URL: /mount/Plex/Jacob/plex/TV/Lucifer/LUCIFER - Complete Season 2 S02 (2016-2017) - 720p AMZN WebRip x264/LUCIFER - S02 E12 - Love Handles (720p AMZN WebRip).mp4
Dec 16, 2021 05:03:56.795 [0x70a7ed48] DEBUG - [JobRunner] Job running: FFMPEG_EXTERNAL_LIBS='/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/fb9eae3-4185-linux-armv7neon/' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' '/usr/lib/plexmediaserver/Plex Transcoder' '-codec:#0x02' 'ac3' '-analyzeduration' '20000000' '-probesize' '20000000' '-i' '/mount/Plex/Jacob/plex/TV/Lucifer/LUCIFER - Complete Season 2 S02 (2016-2017) - 720p AMZN WebRip x264/LUCIFER - S02 E12 - Love Handles (720p AMZN WebRip).mp4' '-filter_complex' '[0:#0x02] aresample=async=1:ocl='\''5.1'\'':rematrix_maxval=0.000000dB:osr=48000[0]' '-map' '[0]' '-metadata:s:0' 'language=eng' '-codec:0' 'flac' '-b:0' '4096k' '-f' 'flac' '-map_metadata' '-1' '-map_chapters' '-1' '-t' '1318.992' '/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Detection/caa379fd-c16c-4b49-b5f4-0b2c9944dbd6' '-y' '-nostats' '-loglevel' 'quiet' '-loglevel_plex' 'error' '-progressurl' 'http://127.0.0.1:32400/video/:/transcode/session/b95d65ad-a334-437c-bb1e-fd59bcd3b4bb/bca7efff-416f-4e65-b88f-a5738d186334/progress'
Dec 16, 2021 05:03:56.795 [0x70a7ed48] DEBUG - [JobRunner] Jobs: Starting child process with pid 19139
Dec 16, 2021 05:03:56.820 [0x700a4d48] DEBUG - Request: [127.0.0.1:53680 (Loopback)] PUT /video/:/transcode/session/b95d65ad-a334-437c-bb1e-fd59bcd3b4bb/bca7efff-416f-4e65-b88f-a5738d186334/progress?status=startup (2 live) Signed-in Token (Jacob.Allen) (range: bytes=0-) 
Dec 16, 2021 05:03:56.821 [0x7156bd48] DEBUG - Completed: [127.0.0.1:53680] 204 PUT /video/:/transcode/session/b95d65ad-a334-437c-bb1e-fd59bcd3b4bb/bca7efff-416f-4e65-b88f-a5738d186334/progress?status=startup (2 live) 1ms 203 bytes (pipelined: 1) (range: bytes=0-) 
Dec 16, 2021 05:03:56.831 [0x700a4d48] DEBUG - Request: [127.0.0.1:53680 (Loopback)] PUT /video/:/transcode/session/b95d65ad-a334-437c-bb1e-fd59bcd3b4bb/bca7efff-416f-4e65-b88f-a5738d186334/progress?status=startup (2 live) Signed-in Token (Jacob.Allen) (range: bytes=0-) 
Dec 16, 2021 05:03:56.832 [0x7156bd48] DEBUG - Completed: [127.0.0.1:53680] 204 PUT /video/:/transcode/session/b95d65ad-a334-437c-bb1e-fd59bcd3b4bb/bca7efff-416f-4e65-b88f-a5738d186334/progress?status=startup (2 live) 1ms 203 bytes (pipelined: 2) (range: bytes=0-) 
Dec 16, 2021 05:03:56.832 [0x700a4d48] DEBUG - Request: [127.0.0.1:53680 (Loopback)] PUT /video/:/transcode/session/b95d65ad-a334-437c-bb1e-fd59bcd3b4bb/bca7efff-416f-4e65-b88f-a5738d186334/progress?status=opening (2 live) Signed-in Token (Jacob.Allen) (range: bytes=0-) 
Dec 16, 2021 05:03:56.833 [0x7156bd48] DEBUG - Completed: [127.0.0.1:53680] 204 PUT /video/:/transcode/session/b95d65ad-a334-437c-bb1e-fd59bcd3b4bb/bca7efff-416f-4e65-b88f-a5738d186334/progress?status=opening (2 live) 1ms 203 bytes (pipelined: 3) (range: bytes=0-) 
Dec 16, 2021 05:03:56.835 [0x730f7d48] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Media Fingerprinter' exit code for process 19013 is -9 (signal: Killed)
Dec 16, 2021 05:03:57.147 [0x700a4d48] DEBUG - Request: [127.0.0.1:53680 (Loopback)] PUT /video/:/transcode/session/b95d65ad-a334-437c-bb1e-fd59bcd3b4bb/bca7efff-416f-4e65-b88f-a5738d186334/progress?status=opened (2 live) Signed-in Token (Jacob.Allen) (range: bytes=0-) 
Dec 16, 2021 05:03:57.148 [0x71548d48] DEBUG - Completed: [127.0.0.1:53680] 204 PUT /video/:/transcode/session/b95d65ad-a334-437c-bb1e-fd59bcd3b4bb/bca7efff-416f-4e65-b88f-a5738d186334/progress?status=opened (2 live) 1ms 203 bytes (pipelined: 4) (range: bytes=0-) 

No. Not sure why that would be showing up as I haven’t tried to play that media today

@Jacob_Allen

Somebody did :slight_smile:

Can you check that video please and see what you get ?

Just played that particular media. No issues at all

Ok… so that one was apparently they started playback then changed their mind. Oh well

Regarding PMS versions -

1.24.5.5173 is PRE transcoder update
1.24.5.5286 is POST transcoder update.
1.24.5.5319 is contains FIXES for the transcoder update

Point 5 - not possible for MKV to be direct played.

Yes it is possible but not all players will read it. Nvidia Shield will take it without blinking. Apple wants FMP4 format. Others want MP4 or MPEG2/MPEG-TS

Point 6 - When it occurs

The default transcoder buffer is approximately 2 minutes buffer-ahead (transcoder sleeps after it fills the output buffer)

What is your current buffer allocation time? (default? Something else?)

My question

Do you have a VaapiDriver override in the Preferences.xml file ?

With my direct play question for mkv i was specifically referencing playback via browser

For me, my Transcoder default throttle buffer is the default (60s). if i change it to 30s/120s/150s, it buffers at the same timestamp. This is with direct stream on both video and audio (AAC). If i change to a version of the file with AC3 causing it to just transcode audio to AAC @ 150s buffer, stops at same timestamp.

I don’t know of any browsers which accept MKV files.

They were all designed around MP4 (before MKV was a thing).

MP4 files permit being “optimized for streaming” (geometry information relocated to the front of the file) which is why they’re so popular for embedded videos in web pages. This is common knowledge,

FFMPEG has special 2nd pass option to relocate the MOOV object which supports this. MKV files can also be optimized but it’s not commonly known.

Browser playback is fraught with pitfalls.

Any one of hundreds of plug-ins / filters can (and often do) break things when triggered.

Try running Plex/web with a JavaScript (JS) blocker and a popup blocker active :rofl:

Browsers must also garbage collect their own memory. They are frame-buffer devices with little-to-NO smarts.

Chrome purportedly has access to the GPU for some acceleration of specific graphics items but I’ve never seen where it will do anything for video frame painting.

It would be interesting to calculate, using the known bit rates , to calculate how much data gets sent to the browser before it chokes.

Is it the same amount across all test cases using different conditions (audio or video) ?

I didn’t particularly care about the mkv direct playing thing, was just a curiousity :slight_smile:

Is it the same amount across all test cases using different conditions (audio or video) ?

hmm, for the issue, only thing i can say for sure right now as i said previously, was that in Edge it was stopping at 1m59s and 1m44s in Firefox (same server, same file). I’m not in a position at the moment to test against against my prod/qa/beta server as i’m remote and it’ll transcode.
Since i reproduced the problem with a new server instance on my laptop, i’ve been testing locally against that with multiple server versions. So I can test whatever settings you want against that right now.

Here’s something that may be interesting though in that vein…
So i take a cleaned version of the full file (i cleaned out extra embedded audio streams/chapters/subs and just left the ac3 stream) @ 11.4 Mbps total bitrate and test it and it stops at 1m59s, right. I trim it down to a clip of the first 4 mins of the file (4m3s exactly, guess it’s clipping on a key frame), it shows the bitrate as 10.1 Mbps. Test. Stops at 1m59s still. Trim down to 3 mins (3m1s). Shows 8.3 Mbps. Test. Stops at 1m44s. Trim down to 2 mins (2m9s). Shows 6.6 Mbps. Test. Doesn’t stop, finishes out the file.

EDIT: Stops = Buffering

That does stink of a missing Key frame.

There’s space to be saved by trimming key frames but there is also a healthy cost when streaming and that key frame gets damaged or droped. You’re stuck until the next one – which is a long time.

I have a few fires to put out here today but will see what I can craft while you’re AFK.

Not a problem, we don’t play in a browser normally, so won’t affect us until a fix.

Here’s something i just noticed in the dashboard. If i play any of the different length versions of the file i just mentioned, it shows all the files as being 2m9s long. May be a clue? SS attached for the cleaned 11.4 Mbps 1h45m14s version playing.

Untitled

And then i can forward past that mark and get the obviously wrong…

Untitled2

The 2 other problem mkvs i’ve been testing (that i haven’t cleaned/trimmed at all) don’t show the length like this; theirs is correct.

Plex Dance” those files

(move out, scan, empty trash, clean bundles, move back, wait for it to populate the metadata )

Can you msg me so i can send you a google sheets link to test data? Not comfortable posting some of the data in it publicly

I have similar ongoing issues with the plex web client and plexmediaserver_1.25.2.5319 (and many prior releases) on ubuntu 20.04.3 on amd64. I will get a pinwheel part way through playback, then if I try to skip to the next file, I get the error content is unavailable. If I refresh the window everything is fine until the next time it pinwheels. Client browser is Chrome or Firefox on ubuntu 21.10.

Watching an mkv file right now in chrome , which I have to transcode to ~8mbps because playing back the original bitrate will cause chrome/firefox to buffer endlessly after a minute or two, I had an issue with the buffer animation staying on the web player even though the content was playing just fine. When I refreshed the window plex decided I hadn’t watched any of the film since I turned transcoding on a few minutes in.

@SomeGuyinCanada

Going to need to see the DEBUG logs ZIP file please which captures the start of the playback.

There’s so much happening right at that moment, it’s impossible to diagnose without seeing what’s happening.

I have similar problem. But period is about 80 seconds.

@ChuckPa , what should I do to collect necessary logs and send them to you?

@yupiter822

Verify DEBUG logging is enabled (which is the default), and VERBOSE logging is disabled (also the default)

Start playback,
Let play until the pause and recovery.
Stop Playback
Wait 20 seconds for logs to flush and PMS to return to idle.
Settings - Server - Troubleshooting - Download Logs

Attach that ZIP file here for me to review

similar problem with the dreaded spinning yellow circle of death while playing any TV shows. everything was working fine for the LONGEST time till server upgraded recently. now the last month or so many shows that played perfectly now all buffer for around 10-20 seconds then play every 20th frame with chopped audio, never normalizing. nothing on the local LAN has changed. I use the xbox app to stream which used to be flawless. all xboxs are hardwired.

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.