Plex Server cannot handle transcoding with subtitles

Plex Media Server NAS & Devices
42

That I don’t know. It shouldn’t. If you can provide me logs when your machine is doing hw + subtitle burn-in and when doing all software, I can take ask our transcoder expert about it. If you’ve already provided these to ChuckPa I can follow up with him.

43

Looks like there are links to the two logs given by MagaZine back on may 10th.

44

Ok. I see Chuck was already brought this up with the team. I’ll let him provide any updates.

45

Just wanted to update; in my logs I’m specifically using an Android device as the client, however, this issue also applies to other devices.

I just tested out a PS4 and I’m seeing the exact same symptoms. Using software transcoding, I can watch a video that has incompatible subs at real-time. Using hardware transcoding, I get about 2 secs of video accompanied with 15 secs of buffering (so basically unwatchable).

Due to this, I want to confidently say, this isn’t a client issue but rather a server issue. Somewhere in the h/w accelerated pipeline, there’s something severely bogging down a single cpu core causing significantly worse performance than software only mode.

This needs to be investigated and solution figured out because as for now, I have had to turn off h/w acceleration since my shared library has a lot of anime and those tend to have ASS subs that aren’t widely supported which means many devices simply can’t view these videos with h/w acceleration turned on in the server (it seems only iOS/PC devices seem to display those properly without the need for transcoding).

46

I just hit one of my files that has this problem. I’d had a very large version of a show (1.5GB) per episode, which didn’t sit well with me. I think perhaps it might have been the FLAC audio track, as other shows in similar h264 aren’t quite so large. After obtaining an HEVC Main10 file with AAC stereo, I sat down to watch on my Amazon FireTV. And waited. And waited. Oh no.

Looking at my server, it displays:
Video: 1080p (HEVC Main 10) (hw)
→ 1080p (H264) – Transcode (hw)
Audio: English (AAC Stereo)
→ MP3 – Transcode
Subtitles: English Forced (ASS)

This caused it to run extremely slowly. So I dug out my old extremely large file. 9.2 mbps data rate vs the smaller file’s 2.6 mbps data rate. It runs… flawlessly? A bit slow to start up compared to the smaller file, but with subtitle file on, this happens:
Video: 1080p (H.264 high 10)
→ 1080p (H264) – Transcode (hw)
Audio: English (FLAC Stereo)
→ MP3 – Transcode
Subtitles: English (ASS)

Near as I can tell the subtitle is the exact same file due to mediainfo info such as data rate. I even moved the subtitle file from the working video and put it into the slow video, and the slow video was still slow. So what in these audio/video conversions is making it perform so slowly when subtitles are enabled?

EDIT: Ok, I frankenstein’d the files. I took the H264 video and the AAC (non-FLAC) audio track using the same subtitle file. It worked well. Didn’t reduce the file size as much as I expected changing from FLAC to AAC, but it did reduce the bitrate to 8.8 mbps:
Video: 1080p (H.264 High 10)
->1080P (H264)—Transcode (hw)
Audio: English (AAC Stereo)
→ MP3—Transcode
Subtitles: English Forced (ASS)

So the conclusion here is… I’m not sure. Seems that H.265/HEVC files need to be (hw) transcoded FIRST before being sent to the device which then seems to need to transcode it AGAIN. But that’s besides the point I think? Anyway it is strange that if the Plex server had to (hw) transcode the video file AND send a subtitle, then… what, is it burning in the subtitle? Because the instant I turn off the sub file the video plays at full speed.

47

If I may correct that –

Synology can’t handle transcoding subtitles.

All the Synology systems, just like the QNAP counterparts with the J-series processors (that give us HW transcoding) do not have enough raw CPU (compute) power to process subtitles.

How it works:

  1. HW decodes the video
  2. Software text, which has been flagged by the player to Burn-In, calls the CPU to do this because Intel didn’t provide a HW interface
  3. When done, HW encodes the final frame.

It’s a PAIN.

The solutions are:

  1. burn in the subtitles in advance if you always need them
  2. verify your player settings are set to automatic and not “burn -in” (forces this behavior)
  3. Change subtitles to what can be streamed to all (like SRT)
48

Ok, interesting. So, when set to use HW transcoding, it actually HW transcodes twice and software burn-in (software transcode?), all of which uses a single core, and this causes a process that normally runs in real time to now run at 1/15 the normal speed?

I have more questions then, because if you turn off hardware transcoding in the options, my plex server then uses 100% of the cpu to play the file immediately WITH subtitle and there is no issue playing back at normal speed. In fact, looking at the CPU usage, after it made a decent amount of data into the buffer of my player, it shuts down for a while before spinning back up to preload the buffer with more data. On average, it’s full-on half of the time and off the rest of the time, so about 50% CPU usage.

I have done some experimenting, and found that Plex tends to only need HW transcoding when it has to stream an HEVC file AND a subtitle to my FireTV. If I turn off the subtitle, it can suddenly direct-play this HEVC file no problem. So is there a way to determine if a subtitle is being burned or not? Because whether it runs slowly or fast, the Dashboard does not give any text to say if its burned in or not, just that it is playing it. Can Android players use SSA/ASS subs?

And one final edit, with ASS subtitles:
Software encoding only:
H.264:
-Without subtitles: 100% of cpu
-With subtitles: 100% of cpu
H.265:
-Without subtitles: <5% of cpu. Direct-play
-With subtitles: 100% of cpu

Hardware encoding enabled:
H.264:
-Without subtitles: 40% of cpu.
-With subtitles: 40% of cpu.
H.265:
-Without subtitles: <5% of cpu. Direct-play
-With subtitles: 25% of CPU, 15 seconds buffer to run 2 seconds of video. (hw) shows up on both lines of the video stream display.

49

Yes, it stinks but that’s how it is.

The reason it has to transcode is because subtitles are a transcode unto themselves – the burn-in process

The hardware gets engaged because the output must be H.264
This is how you go from HEVC + Subtitle → H.264

HW does the HEVC → H.264, the CPU jumps in the middle and paints the subtitles on each frame in software

50

According to this post made much earlier in the thread, h/w transcoding process is multi-threaded:

With subtitles, you’re just adding another core’s worth of cpu time:

Therefore, it shouldn’t just be eating up a single thread and end up choking due to lack of performance.

Furthermore, this kinda explains why h/w transcoding sucks with subtitles BUT it doesn’t explain why software transcoding doesn’t suck more with subtitles.

Surely the lowley J4125 should be absolutely suffocating in software-only mode with having to first decode h265 in software, then extract each frame to burn-in subs before encoding a h264 video stream in a container compatible with the client all whilst simultaneously transcoding the audio as well.

But no, it doesn’t suffocate, it instead runs ahead of real-time. Why? How?
This hasn’t been explained. According to Plex staff, this shouldn’t be possible as a syno nas “is just NOT up to the task for” something like this. This has been repeated a couple of times even though I have explained it’s possible to experience the opposite. What do I need to do? Do I need to literally take a video showing everything I’ve explained here in real-time in order for it to be understood?

I feel like I’m being ignore and brushed off here with the excuse that ‘it’s just not possible’ and therefore ‘there’s nothing we can do here’ without a proper explanation/rebuttal to why software works & hardware doesn’t. The least you guys could do is add an option in PMS (for NAS owners) to always handle subtitle transcode requests in software-only even if h/w acceleration is enabled for all other scenarios.

At least that way, we still partially get the benefits of hardware acceleration instead of having to go with the extreme option of completing turning it off to get playable performance with anything containing incompatible subs.

51

@MagaZine

I’m sorry but your logic and desire to bypass problems with bandaids is not the solution and does not work in the vast majority of cases

Audio + Video + Subtitles must all stay in sync with each other else there’s no point so any one thread can be a pinch point.

regarding subtitles:

On every Synology, with exception of the Xeon CPUs, subtitles are the downfall. No ifs, ands, or buts.

Trying to paint subtitles, in software, into a 30 Mbps video frame, and keep real-time speed – is not possible for J-series CPUs. I’ve benchmarked this on both Synology and QNAP systems in our lab countless times.

There is one characteristic of the J-series CPU , J4xxx CPUs in particular, with the default Intel IHD video driver which is a degenerate case.

  1. Low bit rate video
  2. exacerbated by tone mapping in a docker container.
  3. Subtitle conversion
  4. Subtitle burning.

I do have something you can try.

  1. Install the Synology Text Editor application

  2. Stop Plex

  3. Navigate into the Plex shared folder and down in until you see “Preferences.xml”

  4. Edit it (right-click, open in Text Editor)

  5. Cursor down to the closing /> on the very bottom line.

  6. Carefully add VaapiDriver="i965" in front of it.

  7. It will look like this when done:
    SomePref="Value" VaapiDriver="i965" />

  8. Save the file

  9. Start Plex

  10. retest

This tells Plex to use the older driver which known better tuned for low bit rate video (under 30 Mbps). It’s extremely effective for those videos < 20 Mbps which would be FASTER when done in software transcoding.

1 Like
Video with subtitles dont work after getting plex pass
52

Thanks for getting back to me @ChuckPa and let me just say, I really do appreciate you helping me out here. I was just frustrated with what was happening.

Anyways, I’ve tried your suggestion of adding the old driver to the preferences.xml and… it worked! Perfectly so. Performance was just as good as software-only and is exactly the type of solution I was after.

Especially since a significant majority of my library is under 30 Mbps! The few titles I do have over this would be say remuxes from MakeMKV and the like.

However, that’s where the good news ends because PMS was very unstable with this setting and crashes after just a few moments of starting playback (meaning I have to manually restart PMS) and so unfortunately, I’ve had to revert back to default driver that isn’t great in my use case.

Any ideas on how I move forward from here?

53

If you’re trying something, and it works, but then a new issue pops up,
telling me you needed to revert doesn’t get us any closer to a solution.

May I see the debug log files ???

Would you please

  1. Reapply the older driver,
  2. Restart PMS
  3. Verify DEBUG logging ON, VERBOSE OFF
  4. Start Playback
  5. Let Playback fail.
  6. Download the logs ZIP
  7. Attach for me to review
54

Ahh, I thought because it was an old driver, I wouldn’t get support on it. But here are the requested logs, thanks:
Logs.zip (2.9 MB)

By the way, it’s not just that playback fails, but rather plex media server itself fully crashes, so I’ve ripped these logs straight from the log directory in my nas after it stopped running.

55

Well, I’m feeling a little sheepish here. So I know now that despite my shield being super capable of doing lots of things, the Android player itself is based on an Android player called Exoplayer. And this player has very little support for any subtitle beyond SRT. It has limited support for ASS/SSA, but it pretty much ignores all the styling (Karaoke style text pop-in or highlighting). I think if the subtitle is SSA but is still basic text, it would send it to the player for “Direct Play”, since the shield and the exoplayer on it is capable of playing even HEVC video content.

I don’t know what happens if styling is included, or perhaps if it is ASS it includes certain style features not in the original SSA format. Like, I would HOPE it would drop the styling and just send the text as plain-text, but in my experience the player just tells the server to burn it in. Which requires HW transcoding. and then software subtitle transcoding. Which then needs HW transcoding afterwards to combine the two.

Why this one process takes longer by a factor of 10 or more than straight SW transcoding the file once I have no clue. I’d prefer to thrash my CPU doing a SW transcode than to do a HW-SW-HW transcode dance that performs so slowly. Especially as it’s such a pain to swap the ENTIRE SERVER over to SW transcoding for just that one file-type.

I mean, I’d still like to know why plex falls flat on its face when HW trancoding certain files with subtitles fails so badly compared to doing the same in software. But now that I know the reason behind it and how to avoid it (plus I plan to move to a home-built Windows PC to serve Plex in the future), I can deal with it for now.

2 Likes
56

If you can afford to take your plex server offline for a little bit to do some testing, I highly recommend trying @ChuckPa’s potential solution here:

And let us know if that works. You should be seeing very similar performance to software-only when it comes to troublesome subs but with all the benefits of hardware accel.

The only issue is that for me, it made my Plex server very unstable, and it would randomly crash after a few moments of playback or even being idle. Maybe your setup is a little different and you could have better luck than me. If you don’t and your crashes too then I highly recommend extracting the logs and uploading them here before reverting back to stock configuration so they can be analysed, and the crashing behaviour better understood.

Good luck!

57

I was reading about your little test with the driver. I’d like to try it out, but was waiting to see if ChuckPa would be able to look at the logs and determine if the instability you had was related to this driver use, or something else. If it was driver-related, I wasn’t going to try it out. If it was something else, I was going to try. But tonight when nothing is recording or being watched, I’ll try it on my end for a day (or until I find player crashes).

I’d still like to know why the specific combo of HW-transcode HEVC video + ASS subtitle makes it perform worse than SW transcoding. I’d like to have the server fall back on SW transcode rather than fail so badly doing the current arrangement for these specific file, rather than enabling SW transcode server-wide.

58

@MagaZine

Which device is:

192.168.1.126
and
192.168.1.128

please ?

I am seeing where it

  1. Sees the playback requested
  2. Makes the determination to
    a. Use HW decode
    b. Use HW encode
    c. Use Software Burn-in of foreign language subtitles
Jun 01, 2021 10:24:08.773 [0x7feee45a4b38] DEBUG - [Transcode] Selected a foreign audio track: jpn
Jun 01, 2021 10:24:08.773 [0x7feee45a4b38] DEBUG - [Transcode] Subtitles: Found a candidate subtitle language [eng] for a foreign film
Jun 01, 2021 10:24:08.773 [0x7feee45a4b38] DEBUG - [Transcode] Audio Stream: 122861, Subtitle Stream: 122863
Jun 01, 2021 10:24:08.774 [0x7feee45a4b38] DEBUG - [Transcode] Found session GUID of a34ba768d7f196fa-com-plexapp-android in session start.
Jun 01, 2021 10:24:08.774 [0x7feee45a4b38] DEBUG - [Transcode] Using session GUID a34ba768d7f196fa-com-plexapp-android for new transcode session.
Jun 01, 2021 10:24:08.774 [0x7feee45a4b38] DEBUG - [Transcode] Cleaning directory for session a34ba768d7f196fa-com-plexapp-android ()
Jun 01, 2021 10:24:08.774 [0x7feee5addb38] DEBUG - Completed: [192.168.1.126:46610] 206 GET /video/:/transcode/universal/start.m3u8?advancedSubtitles=text&audioBoost=120&autoAdjustQuality=0&directPlay=0&directStream=1&directStreamAudio=1&fastSeek=1&hasMDE=1&location=lan&maxVideoBitrate=200000&mediaBufferSize=209664&mediaIndex=0&partIndex=0&path=%2Flibrary%2Fmetadata%2F14718&protocol=hls&session=a34ba768d7f196fa-com-plexapp-android&subtitles=burn&subtitleSize=150&videoBitrate=200000&videoQuality=100&videoResolution=3840x2160 (21 live) TLS 11ms 394 bytes (range: bytes=0-) 
Jun 01, 2021 10:24:08.899 [0x7feee4e74b38] DEBUG - Request: [192.168.1.126:46612 (Subnet)] GET /video/:/transcode/universal/session/a34ba768d7f196fa-com-plexapp-android/base/index.m3u8 (21 live) TLS Signed-in
Jun 01, 2021 10:24:08.899 [0x7feee4e74b38] DEBUG - [Transcode] Found session GUID of a34ba768d7f196fa-com-plexapp-android in session start.
Jun 01, 2021 10:24:08.899 [0x7feee4e74b38] DEBUG - [Transcode] Starting a transcode session a34ba768d7f196fa-com-plexapp-android at offset -1.0 (state=3)
Jun 01, 2021 10:24:08.899 [0x7feee4e74b38] DEBUG - [Transcode] TPU: hardware transcoding: using hardware decode accelerator vaapi
Jun 01, 2021 10:24:08.899 [0x7feee4e74b38] DEBUG - [Transcode] TPU: hardware transcoding: zero-copy support present
Jun 01, 2021 10:24:08.899 [0x7feee4e74b38] DEBUG - [Transcode] TPU: hardware transcoding: not using zero-copy because subtitle burning is required
Jun 01, 2021 10:24:08.899 [0x7feee4e74b38] DEBUG - [Transcode] [Universal] Using local file path instead of URL: /volume1/Media/TV Shows/Attack on Titan (2013)/Season 01/Attack on Titan (2013) - S01E01 (001) - To You in 2000 Years The Fall of Shiganshina Part 1 [Bluray-1080p]-NewbSubs.mkv
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API vaapi
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] [FFMPEG] - Format 0x32315659 -> yuv420p.
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] [FFMPEG] - Format 0x30323449 -> yuv420p.
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] [FFMPEG] - Format 0x3231564e -> nv12.
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] [FFMPEG] - Format 0x32595559 -> yuyv422.
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] [FFMPEG] - Format 0x59565955 -> uyvy422.
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] [FFMPEG] - Format 0x48323234 -> yuv422p.
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] [FFMPEG] - Format 0x58424752 -> rgb0.
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] [FFMPEG] - Format 0x58524742 -> bgr0.
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] [FFMPEG] - Format 0x30313050 -> p010le.
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] [FFMPEG] - Created surface 0x4000000.
Jun 01, 2021 10:24:08.900 [0x7feee4e74b38] DEBUG - [Transcode] [FFMPEG] - Direct mapping possible.
Jun 01, 2021 10:24:08.901 [0x7feee4e74b38] DEBUG - [Transcode] TPU: hardware transcoding: final decoder: vaapi, final encoder: vaapi
Jun 01, 2021 10:24:08.901 [0x7feee4e74b38] DEBUG - [Transcode/JobRunner] Job running: FFMPEG_EXTERNAL_LIBS='/volume1/Plex/Library/Application\ Support/Plex\ Media\ Server/Codecs/fa235d6-3858-linux-x86_64/' LIBVA_DRIVERS_PATH='/volume1/@appstore/Plex Media Server/lib/dri' XDG_CACHE_HOME='/volume1/Plex/Library/Application Support/Plex Media Server/Cache' XDG_DATA_HOME='/volume1/@appstore/Plex Media Server/Resources' X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxx8' '/volume1/@appstore/Plex Media Server/Plex Transcoder' '-codec:0' 'hevc' '-hwaccel:0' 'vaapi' '-hwaccel_fallback_threshold:0' '10' '-hwaccel_device:0' 'vaapi' '-analyzeduration' '20000000' '-probesize' '20000000' '-i' '/volume1/Media/TV Shows/Attack on Titan (2013)/Season 01/Attack on Titan (2013) - S01E01 (001) - To You in 2000 Years The Fall of Shiganshina Part 1 [Bluray-1080p]-NewbSubs.mkv' '-map_inlineass' '0:4' '-filter_complex' '[0:0]scale=w=1920:h=1080[0];[0]format=pix_fmts=nv12[1];[1]inlineass=font_scale=1.500000:font_path=/volume1/@appstore/Plex\\\ Media\\\ Server/Resources/Fonts/DejaVuSans-Regular.ttf:fontconfig_file=/volume1/@appstore/Plex\\\ Media\\\ Server/Resources/fonts.conf:language=en[2];[2]hwupload[3]' '-map' '[3]' '-metadata:s:0' 'language=jpn' '-codec:0' 'h264_vaapi' '-b:0' '17104k' '-maxrate:0' '22806k' '-bufsize:0' '45612k' '-r:0' '23.975999999999999' '-force_key_frames:0' 'expr:gte(t,n_forced*1)' '-map' '0:2' '-metadata:s:1' 'language=jpn' '-codec:1' 'copy' '-copypriorss:1' '0' '-segment_format' 'matroska' '-f' 'ssegment' '-individual_header_trailer' '0' '-flags' '+global_header' '-segment_format_options' 'output_ts_offset=10' '-segment_header_filename' 'header' '-segment_time' '1' '-segment_start_number' '0' '-segment_copyts' '1' '-segment_time_delta' '0.0625' '-segment_list' 'http://127.0.0.1:32400/video/:/transcode/session/a34ba768d7f196fa-com-plexapp-android/52cdbcb5-f80c-487c-bcbe-6d3bafda15cc/seglist?X-Plex-Http-Pipeline=infinite' '-segment_list_type' 'csv' '-segment_list_size' '5' '-segment_list_separate_stream_times' '1' '-segment_list_unfinished' '1' '-max_delay' '5000000' '-avoid_negative_ts' 'disabled' '-map_metadata:g' '-1' '-map_metadata:c' '-1' '-map_chapters' '-1' 'media-%05d.ts' '-map' '0:4' '-f' 'null' '-codec' 'ass' 'nullfile' '-start_at_zero' '-copyts' '-vsync' 'cfr' '-init_hw_device' 'vaapi=vaapi:,driver=i965' '-filter_hw_device' 'vaapi' '-y' '-nostats' '-loglevel' 'quiet' '-loglevel_plex' 'error' '-progressurl' 'http://127.0.0.1:32400/video/:/transcode/session/a34ba768d7f196fa-com-plexapp-android/52cdbcb5-f80c-487c-bcbe-6d3bafda15cc/progress'
Jun 01, 2021 10:24:08.902 [0x7feee4e74b38] DEBUG - [Transcode/JobRunner] Jobs: Starting child process with pid 17177
Jun 01, 2021 10:24:08.913 [0x7feee4e97b38] DEBUG - Request: [127.0.0.1:54200 (Loopback)] PUT /video/:/transcode/session/a34ba768d7f196fa-com-plexapp-android/52cdbcb5-f80c-487c-bcbe-6d3bafda15cc/progress?status=startup (22 live) Signed-in Token (naimthaque) (range: bytes=0-)
  1. Plays along – apparently normally.
bcbe-6d3bafda15cc/media-00000.ts is 381205 (of total: 381205).
Jun 01, 2021 10:24:10.257 [0x7feee4e74b38] DEBUG - Request: [192.168.1.126:46618 (Subnet)] GET /video/:/transcode/universal/session/a34ba768d7f196fa-com-plexapp-android/base/00001.ts (23 live) TLS Signed-in
Jun 01, 2021 10:24:10.257 [0x7feee4e74b38] DEBUG - [Transcode/a34ba768d7f196fa-com-plexapp-android] Asked for segment 1 from session.
Jun 01, 2021 10:24:10.294 [0x7feee5abab38] DEBUG - Completed: [192.168.1.126:46616] 200 GET /video/:/transcode/universal/session/a34ba768d7f196fa-com-plexapp-android/base/00000.ts (23 live) TLS 111ms 381205 bytes (pipelined: 1)
Jun 01, 2021 10:24:10.294 [0x7feee5abab38] DEBUG - Removed transcode data consumer, active count 1 => 0
Jun 01, 2021 10:24:10.661 [0x7feee4581b38] DEBUG - [Transcode] Transcoder segment range: 0 - 1 (1)
Jun 01, 2021 10:24:10.661 [0x7feee4efdb38] DEBUG - [Transcode] Transcoder segment range: 0 - 2 (1)
Jun 01, 2021 10:24:10.757 [0x7feee4e74b38] DEBUG - [Transcode/a34ba768d7f196fa-com-plexapp-android] Returning segment 1 from session
Jun 01, 2021 10:24:10.757 [0x7feee4e74b38] DEBUG - Content-Length of /volume1/Plex/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-a34ba768d7f196fa-com-plexapp-android-52cdbcb5-f80c-487c-bcbe-6d3bafda15cc/media-00001.ts is 1499867 (of total: 1499867).
Jun 01, 2021 10:24:10.835 [0x7feee4edab38] DEBUG - Request: [192.168.1.126:46616 (Subnet)] GET /video/:/transcode/universal/session/a34ba768d7f196fa-com-plexapp-android/base/00002.ts (22 live) TLS Signed-in
Jun 01, 2021 10:24:10.836 [0x7feee4edab38] DEBUG - [Transcode/a34ba768d7f196fa-com-plexapp-android] Asked for segment 2 from session.
Jun 01, 2021 10:24:11.077 [0x7feee5abab38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:24:11.077 [0x7feee45a4b38] DEBUG - Request: [192.168.1.128:64216 (Subnet)] GET /statistics/bandwidth?timespan=6 (22 live) TLS GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:24:11.079 [0x7feee5abab38] DEBUG - Completed: [192.168.1.128:64216] 200 GET /statistics/bandwidth?timespan=6 (22 live) TLS GZIP 1ms 1065 bytes (pipelined: 19)
Jun 01, 2021 10:24:11.393 [0x7feee4efdb38] DEBUG - [Transcode] Transcoder segment range: 0 - 2 (2)
Jun 01, 2021 10:24:11.393 [0x7feee4e74b38] DEBUG - [Transcode] Transcoder segment range: 0 - 3 (2)
Jun 01, 2021 10:24:11.436 [0x7feee4edab38] DEBUG - [Transcode/a34ba768d7f196fa-com-plexapp-android] Returning segment 2 from session
Jun 01, 2021 10:24:11.436 [0x7feee4edab38] DEBUG - Content-Length of /volume1/Plex/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-a34ba768d7f196fa-com-plexapp-android-52cdbcb5-f80c-487c-bcbe-6d3bafda15cc/media-00002.ts is 2877843 (of total: 2877843).
Jun 01, 2021 10:24:11.472 [0x7feee5abab38] DEBUG - Completed: [192.168.1.126:46618] 200 GET /video/:/transcode/universal/session/a34ba768d7f196fa-com-plexapp-android/base/00001.ts (21 live) TLS 1216ms 1499867 bytes (pipelined: 1)
Jun 01, 2021 10:24:11.472 [0x7feee5abab38] DEBUG - Removed transcode data consumer, active count 2 => 1
Jun 01, 2021 10:24:11.500 [0x7feee4efdb38] DEBUG - Request: [192.168.1.126:46618 (Subnet)] GET /video/:/transcode/universal/session/a34ba768d7f196fa-com-plexapp-android/base/00003.ts (21 live) TLS Signed-in
Jun 01, 2021 10:24:11.500 [0x7feee4efdb38] DEBUG - [Transcode/a34ba768d7f196fa-com-plexapp-android] Asked for segment 3 from session.
Jun 01, 2021 10:24:12.090 [0x7feee5abab38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:24:12.091 [0x7feee4e97b38] DEBUG - Request: [192.168.1.128:64216 (Subnet)] GET /statistics/bandwidth?timespan=6 (20 live) TLS GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:24:12.092 [0x7feee5abab38] DEBUG - Completed: [192.168.1.128:64216] 200 GET /statistics/bandwidth?timespan=6 (20 live) TLS GZIP 1ms 1079 bytes (pipelined: 20)
Jun 01, 2021 10:24:12.124 [0x7feee4e74b38] DEBUG - [Transcode] Transcoder segment range: 0 - 3 (3)
Jun 01, 2021 10:24:12.124 [0x7feee4edab38] DEBUG - [Transcode] Transcoder segment range: 0 - 4 (3)
Jun 01, 2021 10:24:12.201 [0x7feee4efdb38] DEBUG - [Transcode/a34ba768d7f196fa-com-plexapp-android] Returning segment 3 from session
Jun 01, 2021 10:24:12.201 [0x7feee4efdb38] DEBUG - Content-Length of /volume1/Plex/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-a34ba768d7f196fa-com-plexapp-android-52cdbcb5-f80c-487c-bcbe-6d3bafda15cc/media-00003.ts is 3182726 (of total: 3182726).
Jun 01, 2021 10:24:12.273 [0x7feee5abab38] DEBUG - Completed: [192.168.1.126:46616] 200 GET /video/:/transcode/universal/session/a34ba768d7f196fa-com-plexapp-android/base/00002.ts (20 live) TLS 1438ms 2877843 bytes (pipelined: 2)
Jun 01, 2021 10:24:12.274 [0x7feee5abab38] DEBUG - Removed transcode data consumer, active count 2 => 1
Jun 01, 2021 10:24:12.292 [0x7feee4581b38] DEBUG - Request: [192.168.1.126:46616 (Subnet)] GET /video/:/transcode/universal/session/a34ba768d7f196fa-com-plexapp-android/base/00004.ts (20 live) TLS Signed-in
Jun 01, 2021 10:24:12.292 [0x7feee4581b38] DEBUG - [Transcode/a34ba768d7f196fa-com-plexapp-android] Asked for segment 4 from session.
Jun 01, 2021 10:24:12.858 [0x7feee4e74b38] DEBUG - [Transcode] Transcoder segment range: 0 - 4 (4)
Jun 01, 2021 10:24:12.858 [0x7feee4e74b38] DEBUG - [Transcode] Transcoder segment range: 0 - 5 (4)
Jun 01, 2021 10:24:12.892 [0x7feee4581b38] DEBUG - [Transcode/a34ba768d7f196fa-com-plexapp-android] Returning segment 4 from session
Jun 01, 2021 10:24:12.892 [0x7feee4581b38] DEBUG - Content-Length of /volume1/Plex/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-a34ba768d7f196fa-com-plexapp-android-52cdbcb5-f80c-487c-bcbe-6d3bafda15cc/media-00004.ts is 2392449 (of total: 2392449).
  1. Then just stops and another playback starts.
Jun 01, 2021 10:24:59.399 [0x7feee5addb38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:24:59.399 [0x7feee45a4b38] DEBUG - Request: [192.168.1.128:64216 (Subnet)] GET /statistics/bandwidth?timespan=6 (13 live) TLS GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:24:59.402 [0x7feee5addb38] DEBUG - Completed: [192.168.1.128:64216] 200 GET /statistics/bandwidth?timespan=6 (13 live) TLS GZIP 3ms 1958 bytes (pipelined: 87)
Jun 01, 2021 10:24:59.913 [0x7feee4581b38] DEBUG - [Transcode] Transcoder segment range: 0 - 67 (67)
Jun 01, 2021 10:24:59.913 [0x7feee4e97b38] DEBUG - [Transcode] Transcoder segment range: 0 - 68 (67)
Jun 01, 2021 10:24:59.988 [0x7feee4edab38] DEBUG - [Transcode/a34ba768d7f196fa-com-plexapp-android] Returning segment 67 from session
Jun 01, 2021 10:24:59.988 [0x7feee4edab38] DEBUG - Content-Length of /volume1/Plex/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-a34ba768d7f196fa-com-plexapp-android-52cdbcb5-f80c-487c-bcbe-6d3bafda15cc/media-00067.ts is 2496465 (of total: 2496465).
Jun 01, 2021 10:25:00.033 [0x7feee4efdb38] DEBUG - Request: [192.168.1.126:46616 (Subnet)] GET /video/:/transcode/universal/session/a34ba768d7f196fa-com-plexapp-android/base/00068.ts (14 live) TLS Signed-in
Jun 01, 2021 10:25:00.033 [0x7feee4efdb38] DEBUG - [Transcode/a34ba768d7f196fa-com-plexapp-android] Asked for segment 68 from session.
Jun 01, 2021 10:25:00.129 [0x7feee5addb38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.129 [0x7feee45a4b38] DEBUG - Request: [127.0.0.1:54520 (Loopback)] GET /library/sections (15 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.133 [0x7feee5abab38] DEBUG - Completed: [127.0.0.1:54520] 200 GET /library/sections (15 live) GZIP 4ms 1853 bytes
Jun 01, 2021 10:25:00.142 [0x7feee5addb38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.142 [0x7feee4581b38] DEBUG - Request: [127.0.0.1:54522 (Loopback)] GET /library/sections/3/recentlyAdded (15 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.152 [0x7feee5abab38] DEBUG - Completed: [127.0.0.1:54522] 200 GET /library/sections/3/recentlyAdded (15 live) GZIP 9ms 4770 bytes
Jun 01, 2021 10:25:00.165 [0x7feee5addb38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.165 [0x7feee5abab38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.165 [0x7feee5addb38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.165 [0x7feee4edab38] DEBUG - Request: [127.0.0.1:54526 (Loopback)] GET /library/metadata/9312 (23 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.165 [0x7feee4e97b38] DEBUG - Request: [127.0.0.1:54524 (Loopback)] GET /library/metadata/9318 (23 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.165 [0x7feee5addb38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.165 [0x7feee45a4b38] DEBUG - Request: [127.0.0.1:54528 (Loopback)] GET /library/metadata/912 (23 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.165 [0x7feee5abab38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.165 [0x7feee5addb38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.165 [0x7feee4e74b38] DEBUG - Request: [127.0.0.1:54530 (Loopback)] GET /library/metadata/901 (23 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.165 [0x7feee5abab38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.165 [0x7feee4581b38] DEBUG - Request: [127.0.0.1:54532 (Loopback)] GET /library/metadata/892 (23 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.166 [0x7feee4a18b38] DEBUG - Request: [127.0.0.1:54536 (Loopback)] GET /library/metadata/846 (23 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.167 [0x7feee5abab38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.169 [0x7feee5addb38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.170 [0x7feee4a3bb38] DEBUG - Request: [127.0.0.1:54534 (Loopback)] GET /library/metadata/869 (23 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.173 [0x7feee43d4b38] DEBUG - Request: [127.0.0.1:54540 (Loopback)] GET /library/metadata/697 (23 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.177 [0x7feee37b0b38] DEBUG - Request: [127.0.0.1:54538 (Loopback)] GET /library/metadata/765 (23 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.201 [0x7feee4edab38] DEBUG - It took 80.000000 ms to retrieve 1 items.
Jun 01, 2021 10:25:00.221 [0x7feee37b0b38] DEBUG - It took 60.000000 ms to retrieve 1 items.
Jun 01, 2021 10:25:00.224 [0x7feee4e74b38] DEBUG - It took 110.000000 ms to retrieve 248 items.
Jun 01, 2021 10:25:00.235 [0x7feee4a18b38] DEBUG - It took 150.000000 ms to retrieve 308 items.
Jun 01, 2021 10:25:00.235 [0x7feee4e97b38] DEBUG - It took 150.000000 ms to retrieve 385 items.
Jun 01, 2021 10:25:00.236 [0x7feee43d4b38] DEBUG - It took 120.000000 ms to retrieve 1 items.
Jun 01, 2021 10:25:00.241 [0x7feee4581b38] DEBUG - It took 170.000000 ms to retrieve 429 items.
Jun 01, 2021 10:25:00.242 [0x7feee4a3bb38] DEBUG - It took 120.000000 ms to retrieve 307 items.
Jun 01, 2021 10:25:00.243 [0x7feee45a4b38] DEBUG - It took 160.000000 ms to retrieve 383 items.
Jun 01, 2021 10:25:00.244 [0x7feee4edab38] DEBUG - It took 130.000000 ms to retrieve 327 items.
Jun 01, 2021 10:25:00.264 [0x7feee37b0b38] DEBUG - It took 130.000000 ms to retrieve 295 items.
Jun 01, 2021 10:25:00.270 [0x7feee4e74b38] DEBUG - It took 90.000000 ms to retrieve 248 items.
Jun 01, 2021 10:25:00.271 [0x7feee4a18b38] DEBUG - It took 70.000000 ms to retrieve 1 items.
Jun 01, 2021 10:25:00.277 [0x7feee4e74b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
Jun 01, 2021 10:25:00.277 [0x7feee4e74b38] DEBUG - Selecting best audio stream for part ID 27137 (autoselect: 1 language: en)
Jun 01, 2021 10:25:00.277 [0x7feee4e74b38] DEBUG - We're going to try to auto-select a subtitle.
Jun 01, 2021 10:25:00.277 [0x7feee4e74b38] DEBUG - Subtitles: Found a candidate subtitle language [eng] for a foreign film
Jun 01, 2021 10:25:00.277 [0x7feee4e74b38] DEBUG - Audio Stream: 100031, Subtitle Stream: 100032
Jun 01, 2021 10:25:00.279 [0x7feee4edab38] DEBUG - It took 80.000000 ms to retrieve 1 items.
Jun 01, 2021 10:25:00.280 [0x7feee5abab38] DEBUG - Completed: [127.0.0.1:54530] 200 GET /library/metadata/901 (23 live) GZIP 114ms 4919 bytes
Jun 01, 2021 10:25:00.284 [0x7feee5addb38] DEBUG - Auth: authenticated user 1 as naimthaque
Jun 01, 2021 10:25:00.289 [0x7feee4e74b38] DEBUG - Request: [127.0.0.1:54542 (Loopback)] GET /library/metadata/901 (23 live) GZIP Signed-in Token (naimthaque)
Jun 01, 2021 10:25:00.290 [0x7feee4a3bb38] DEBUG - It took 80.000000 ms to retrieve 307 items.
Jun 01, 2021 10:25:00.295 [0x7feee43d4b38] DEBUG - It took 180.000000 ms to retrieve 366 items.

If there is instability here, I don’t see it on the server side.

59

.126 is my Android phone and .128 is my desktop running Plex for Windows.

I’ve retested again today (that’s where the logs are from), and playback was fine for the couple of minutes that I tested it for (which is what you’re seeing). However, after a while (like maybe 2-5 minutes after playback ended), PMS just crashes. Is it that maybe the crashes aren’t getting recorded, if you can’t see them, since it just happens suddenly?

60

Let’s please word this carefully so I am clear.

  1. PMS (the entire server) crashes?
    -or-
  2. The player (entire player) crashes?
    -or-
  3. Playback blows up and stops but the player stays running?

I am asking because:

  1. Server crashes are nearly immediate

  2. Player crashes – Out of my league

  3. Transcoder crashes happen if it encounters:
    a. really corrupted files
    b. runs out of memory (system wide)

61

It’s a PMS crash. As in, I have to go into package centre and manually start PMS back-up type crash.