Converting to a lower quality fails with Hardware-Accelerated Streaming in Plex Web

[ChuckPa]

Thanks for the logs. You made diagnosis trivial.

1. You have more than 8192 directories with media being monitored.
2. The Linux default is 8192 but can be easily updated (this is a host resource)
3. The transcoder needs two “inotify” slots but your media has consumed them all.
4. The solution - Increase the table size

Increase the number of directories Linux can monitor (Notify)

The default size of the Linux inotify table is 8192 directories. When PMS is configured to update automatically when media is added, with properly organized media, especially music, this table rapidly fills and exceeds the default allocation. The solution to this is straight forward. Increasing the table size is easy. The first step is to determine how many directories to allocate, A. Determine how many directories are currently in use: sudo find /dir1 /dir2 /dir3 -type d -print…

From your logs:

Jul 26, 2020 11:34:47.952 [0x7f8dc632d700] DEBUG - [Notify] Now watching "/home/k8s/movies/hollywood/Love.Unleashed.2019.WEBDL-1080p.h264.EAC3-alfaHD"
Jul 26, 2020 11:34:47.953 [0x7f8dc632d700] DEBUG - [Notify] Now watching "/home/k8s/movies/hollywood/House.Hunting.2013.Bluray-1080p.x264.DTS-househunting"
Jul 26, 2020 11:34:47.953 [0x7f8dc632d700] DEBUG - [Notify] Now watching "/home/k8s/movies/hollywood/The.Grey.2011.Blu-ray.1080p.DTS.H264-chd"
Jul 26, 2020 11:34:47.955 [0x7f8dc632d700] DEBUG - [Notify] Now watching "/home/k8s/movies/hollywood/The.Big.Boss.1971.Blu-ray.1080p.DTS.H264-AiRLiNE"
Jul 26, 2020 11:34:47.956 [0x7f8dc632d700] DEBUG - [Notify] Now watching "/home/k8s/movies/hollywood/The.Silencing.2020.WEBDL-1080p.x264.AC3-EVO"
Jul 26, 2020 11:34:47.957 [0x7f8dc632d700] DEBUG - [Notify] Now watching "/home/k8s/movies/hollywood/The.Resurrection.of.Gavin.Stone.2017.Bluray-1080p.x264.DTS-HDChina"
Jul 26, 2020 11:34:47.959 [0x7f8dc632d700] DEBUG - [Notify] Now watching "/home/k8s/movies/hollywood/Neighbors.2014.Blu-ray.1080p.DTS.H264-SPARKS"
Jul 26, 2020 11:34:47.960 [0x7f8dc632d700] ERROR - [Notify] Failed to add watch for "/home/k8s/movies/hollywood/Grace.of.My.Heart.1996.Bluray-1080p.Proper.x264.AC3-nikt0" (28: No space left on device)
Jul 26, 2020 11:34:47.961 [0x7f8dc632d700] ERROR - [Notify] Failed to add watch for "/home/k8s/movies/hollywood/Loving.Annabelle.2006.WEBDL-1080p.x264.EAC3-TrollHD" (28: No space left on device)
Jul 26, 2020 11:34:47.962 [0x7f8dc632d700] ERROR - [Notify] Failed to add watch for "/home/k8s/movies/hollywood/The.Dentist.1996.Bluray-1080p.x264.DTS-FGT" (28: No space left on device)
Jul 26, 2020 11:34:47.964 [0x7f8dc632d700] ERROR - [Notify] Failed to add watch for "/home/k8s/movies/hollywood/Palo.Alto.2013.Bluray-1080p.x264.DTS-WiKi" (28: No space left on device)
Jul 26, 2020 11:34:47.965 [0x7f8dc632d700] ERROR - [Notify] Failed to add watch for "/home/k8s/movies/hollywood/The.Private.Life.of.Sherlock.Holmes.1970.Bluray-1080p.x264.DTS-sinners" (28: No space left on device)
Jul 26, 2020 11:34:47.966 [0x7f8dc632d700] ERROR - [Notify] Failed to add watch for "/home/k8s/movies/hollywood/Used.Cars.1980.Blu-ray.1080p.DTS.H264-AMIABLE" (28: No space left on device)
Jul 26, 2020 11:34:47.967 [0x7f8dc632d700] ERROR - [Notify] Failed to add watch for "/home/k8s/movies/hollywood/Ilsa.the.Mad.Butcher.1977.Bluray-1080p.x264.DTS-ilsatww1080" (28: No space left on device)
Jul 26, 2020 11:34:47.968 [0x7f8dc632d700] ERROR - [Notify] Failed to add watch for "/home/k8s/movies/hollywood/How.to.Be.Single.2016.Blu-ray.1080p.DTS.H264-HDMaNiAcS" (28: No space left on device)
Jul 26, 2020 11:34:47.970 [0x7f8dc632d700] ERROR - [Notify] Failed to add watch for "/home/k8s/movies/hollywood/Hard.to.Hold.1984.WEBDL-1080p.h264.EAC3-monkee" (28: No space left on device)
Jul 26, 2020 11:34:47.970 [0x7f8dc632d700] ERROR - [Notify] Failed to add watch for "/home/k8s/movies/hollywood/How.to.Deal.2003.WEBDL-1080p.h264.EAC3-GLUE" (28: No space left on device)

[geek-baba]

OMG LOL - I actually fixed that when I saw the error log myself, I set it to fs.inotify.max_user_watches=524288, but I didn’t realize that was the issue. Is the number should be more than number of directories? i have over 15k movies and 500 tvshows…just wondering if 524288 is good enough?

EDIT1: now reading through your post which explains how to decide the number and impact on size.

EDIT2: Just to confirm increasing inotify number fixes the issue.

[ChuckPa]

When you count the actual number OF DIRECTORIES you use, what do you get?

Look at the math I show.

1. Get count
2. Divide by 32768 - take integer result.
3. Add 1
4. Multiply by 32768
5. Use this value

If you grow more rapidly, use 65536 or 131072 (multiples of 32K)

[mcapplbee]

@ChuckPa,

Sorry to bother you on a Sunday, but is there anything enlightening in my log snapshot provided? I still can’t do hardware transcodes reliably on Plex Web Player.

I do notice that the logs say

Jul 26, 2020 19:22:15.524 [0x7fb0b6bf9700] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Transcoder' exit code for process 6728 is -9 (signal: Killed) 

Right before the transcoder stops, so something is killing it. Nothing in dmesg. Plex web console.log states:

 {
    "type": "log:message",
    "level": 1,
    "message": "[PDE] Player decision failed; the transcode server may be a slow or outdated",
    "time": "2020-07-26T23:18:54.066Z"
  },

[ChuckPa]

@mcapplbee

I see your logs, I see where PMS finds the card, loads the drivers in preparation for using CUDA but does not engage through the Nvidia API.

Is that card capable of transcoding ?
According to this, it’s not. It may be capable of HW graphics but doesn’t appear to be video transcode capable.

What is it ?

Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuTexObjectCreate
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuTexObjectDestroy
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuGLGetDevices_v2
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuGraphicsGLRegisterImage
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuGraphicsUnregisterResource
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuGraphicsMapResources
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuGraphicsUnmapResources
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuGraphicsSubResourceGetMappedArray
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuDeviceGetUuid
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuImportExternalMemory
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuDestroyExternalMemory
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuExternalMemoryGetMappedBuffer
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuExternalMemoryGetMappedMipmappedArray
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuMipmappedArrayGetLevel
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuMipmappedArrayDestroy
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuImportExternalSemaphore
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuDestroyExternalSemaphore
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuSignalExternalSemaphoresAsync
Jul 25, 2020 14:14:32.617 [0x7fad817fa700] DEBUG - [FFMPEG] - Loaded sym: cuWaitExternalSemaphoresAsync
Jul 25, 2020 14:14:32.640 [0x7fae1e1dc700] DEBUG - Auth: authenticated user 1 as someuser
Jul 25, 2020 14:14:32.640 [0x7fad81ffb700] DEBUG - Request: [10.X.Y.Z:60140 (Subnet)] GET /video/:/transcode/universal/subtitles?hasMDE=1&path=%2Flibrary%2Fmetadata%2F5788&mediaIndex=0&partIndex=0&protocol=dash&fastSeek=1&directPlay=0&directStream=1&subtitleSize=100&audioBoost=100&location=lan&maxVideoBitrate=4000&addDebugOverlay=0&autoAdjustQuality=0&directStreamAudio=1&mediaBufferSize=102400&session=j30ixs5qbs2gzxuz5xaw7yn3&subtitles=auto&Accept-Language=en (15 live) TLS GZIP Signed-in Token (someuser)
Jul 25, 2020 14:14:32.640 [0x7fad81ffb700] DEBUG - Found session GUID of j30ixs5qbs2gzxuz5xaw7yn3 in session start.
Jul 25, 2020 14:14:32.641 [0x7fad81ffb700] DEBUG - TranscodeUniversalRequest: using augmented profile Web
Jul 25, 2020 14:14:32.641 [0x7fad81ffb700] DEBUG - Downloading document http://127.0.0.1:32400/library/metadata/5788?checkFiles=1&includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=ijpeog4c06rhgwfsidzg46rq
Jul 25, 2020 14:14:32.641 [0x7fad81ffb700] DEBUG - Auth: authenticated user 1 as someuser
Jul 25, 2020 14:14:32.648 [0x7fad81ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Jul 25, 2020 14:14:32.648 [0x7fad81ffb700] DEBUG - Selecting best audio stream for part ID 12975 (autoselect: 1 language: ja)
Jul 25, 2020 14:14:32.648 [0x7fad81ffb700] DEBUG - We're going to try to auto-select a subtitle.
Jul 25, 2020 14:14:32.648 [0x7fad81ffb700] DEBUG - Selected a foreign audio track: eng
Jul 25, 2020 14:14:32.648 [0x7fad81ffb700] DEBUG - Subtitles: Found a candidate subtitle language [eng] for a foreign film
Jul 25, 2020 14:14:32.648 [0x7fad81ffb700] DEBUG - Audio Stream: 30336, Subtitle Stream: 30337
Jul 25, 2020 14:14:32.649 [0x7fad81ffb700] DEBUG - Found session GUID of j30ixs5qbs2gzxuz5xaw7yn3 in session start.
Jul 25, 2020 14:14:32.649 [0x7fad81ffb700] DEBUG - TranscodeUniversalRequest: using augmented profile Web
Jul 25, 2020 14:14:32.649 [0x7fad81ffb700] DEBUG - Downloading document http://127.0.0.1:32400/library/metadata/5788?checkFiles=1&includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=ijpeog4c06rhgwfsidzg46rq
Jul 25, 2020 14:14:32.649 [0x7fad81ffb700] DEBUG - Auth: authenticated user 1 as someuser
Jul 25, 2020 14:14:32.654 [0x7fad81ffb700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Jul 25, 2020 14:14:32.654 [0x7fad81ffb700] DEBUG - Selecting best audio stream for part ID 12975 (autoselect: 1 language: ja)
Jul 25, 2020 14:14:32.654 [0x7fad81ffb700] DEBUG - We're going to try to auto-select a subtitle.
Jul 25, 2020 14:14:32.654 [0x7fad81ffb700] DEBUG - Selected a foreign audio track: eng
Jul 25, 2020 14:14:32.654 [0x7fad81ffb700] DEBUG - Subtitles: Found a candidate subtitle language [eng] for a foreign film
Jul 25, 2020 14:14:32.654 [0x7fad81ffb700] DEBUG - Audio Stream: 30336, Subtitle Stream: 30337
Jul 25, 2020 14:14:32.654 [0x7fad81ffb700] DEBUG - Found session GUID of j30ixs5qbs2gzxuz5xaw7yn3 in session start.
Jul 25, 2020 14:14:32.654 [0x7fad81ffb700] DEBUG - Cleaning directory for session j30ixs5qbs2gzxuz5xaw7yn3 ()
Jul 25, 2020 14:14:32.655 [0x7fad81ffb700] DEBUG - Starting a transcode session j30ixs5qbs2gzxuz5xaw7yn3 at offset -1.0 (state=3)
Jul 25, 2020 14:14:32.655 [0x7fae0ffff700] DEBUG - Killing job.
Jul 25, 2020 14:14:32.655 [0x7fae0ffff700] DEBUG - Signalling job ID 55731 with 9
Jul 25, 2020 14:14:32.655 [0x7fae0ffff700] DEBUG - Job was already killed, not killing again.
Jul 25, 2020 14:14:32.655 [0x7fae0ffff700] DEBUG - Stopping transcode session qpyax33h9po9sl40r7ropib0
Jul 25, 2020 14:14:32.655 [0x7fad81ffb700] DEBUG - TPU: hardware transcoding: enabled, but no hardware decode accelerator found
Jul 25, 2020 14:14:32.656 [0x7fad81ffb700] DEBUG - [Universal] Using local file path instead of URL: /media/category_three/censored"
Jul 25, 2020 14:14:32.656 [0x7fad81ffb700] DEBUG - TPU: hardware transcoding: final decoder: , final encoder: 
Jul 25, 2020 14:14:32.656 [0x7fad81ffb700] DEBUG - Job running: EAE_ROOT='/tmp/pms-65f9c36d-53e8-4592-8671-680a4a237052/EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/5f603a2-3204-linux-x86_64/' XDG_CACHE_HOME='/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache' XDG_DATA_HOME='/usr/lib/plexmediaserver/Resources' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' '/usr/lib/plexmediaserver/Plex Transcoder' '-codec:0' 'h264' '-codec:1' 'eac3_eae' '-eae_prefix:1' 'j30ixs5qbs2gzxuz5xaw7yn3_' '-ss' '0' '-noaccurate_seek' '-analyzeduration' '20000000' '-probesize' '20000000' '-i' '/media/category_three/censored"
Jul 25, 2020 14:14:32.657 [0x7fad81ffb700] DEBUG - Jobs: Starting child process with pid 55802

Is it in this list?

Video Encode and Decode GPU Support Matrix

[mcapplbee]

Hey @ChuckPA,

Thanks again for taking the time on a Sunday.

Yes, it’s a Quadro P2200 and it is in that list. It’s basically a newer version of the P2000. It’s capable of transcoding - I can get it to transcode on Android Plex Player just fine. The process list populates with a transcoder process and I can select any arbitrary quality without a single problem.

My issue seems only to be with Plex Web, the transcoder will die.

[ChuckPa]

The player is independent here. That’s the disconnect.

Thanks for showing me the transcoder engaging. That confirms PMS is OK.

Let’s try this: Your choice —

1. Turn off any & all browser plug-ins
2. Turn off and run in Incognito mode (no plug-ins)
3. Use a different browser with nothing loaded in it.

I am suspecting it’s the browser or, most likely, one of the plug-ins

If it were the browser or host OS, there would be a huge number of complaints.

[mcapplbee]

Hey @ChuckPA,

It would be nice if it were my browser, but that doesn’t seem to be the case.
I’ve replicated this problem on Windows 10 and Linux - both on Chrome.
I can replicate it on Firefox on Plex Web as well… Not sure what else to try here.

Here is a short Windows 10 screen recording using both Plex Desktop and Chrome Incognito exhibiting the same behavior:

[ChuckPa]

can you escape that please for downloading? The Forum is trying to process it.

[mcapplbee]

Done, didn’t expect that - sorry.
[edit]
Here is the same movie playing on Android with no problem at all. As you can see, I can change the quality settings to whatever I want. nvidia-smi populates with a process for each quality, changing pids when I change the setting.

[ChuckPa]

May I get a snip of that file? about 60 seconds worth (using dd)

I would like to download and see what happens here for me.
I will also run it through some of my tools and see what’s going on with it if I can replicate what you see.

[mcapplbee]

Hello @ChuckPa, Sintel is a free / Creative Commons 3.0 movie - but I’m having this problem with every single piece of media on my Plex server.

You can get the complete movie here (~1GB)
Or if you prefer command line
curl -LO 'http://ftp.nluug.nl/pub/graphics/blender/demo/movies/Sintel.2010.1080p.mkv'

If you just want the 60 second clip you originally requested, it is here (~79MB),
clipped using the following command:ffmpeg -ss 60 -i Sintel.2010.1080p.mkv -c copy -t 60 /media/Sintel.2010.1080p.CLIPPED.mkv
I am able to replicate the problem with the 60s clip - however, it seems there’s a ~10-15% chance the transcoder does not die and the transcode goes through.

I’m not really sure why the transcoder works on the Android player, but I’m having similar “Unable to Play” issues on Samsung Smart TV and Chromecast 2.0 as well.

I’m now starting to worry that the p2200 wasn’t the best choice as I can’t find a lot of people using it for Plex. It seems most people opted for the p2000.

[ChuckPa]

Thank you for the file.

Now for the bad news. I cannot reproduce your problem in Chrome, on Linux (QNAP server running PMS 1.20.0)

[mcapplbee]

@ChuckPA,

Thank you for working late on this. I figured you would not be able to replicate.

My current theory is that Plex is killing its own transcoder (as evidenced by the kill -9), unable to decide whether to stick to NVENC or VAAPI – even though VAAPI is not installed (verified with lsmod | grep va).

The reason I believe the GPU is not at fault is because I’m able to copy the FFMPEG / /usr/lib/plexmediaserver/Plex Transcoder flags and do a “dash” transcode to disk. No error messages are published in Plex Transcoder output when I set -loglevel to info. On the contrary, the command completes successfully every time and appears to be expected FFMPEG output. The GPU has a 300MB vmem process running for the entire transcode until Plex Transcoder exits 0.

I’m able to use mpv to play the dash file that this command generates. Granted it’s only a few minutes broken into dash segments – I’m not familiar enough with the ffmpeg dash flags to transcode the entire file to disk.

Here is a capture of that dash playlist, transcoded to 720p using Plex flags and played through mpv. The skipping is me scrubbing through the timeline, but the playback is quite smooth.

This is a filtered log I see when I try to switch quality on Plex web.
Filter is ls -1 | grep '[a-z]'.log | xargs -d '\n' tail -F 2>/dev/null | grep -i 'hardware\|accelerator\|died\|TPU\|exit\ code\|died\|killing'

Jul 26, 2020 23:18:05.715 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvenc
Jul 26, 2020 23:18:06.032 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API vaapi
Jul 26, 2020 23:18:06.032 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Input/output error
Jul 26, 2020 23:18:06.032 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvdec
Jul 26, 2020 23:18:06.295 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvenc
Jul 26, 2020 23:18:06.584 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API vaapi
Jul 26, 2020 23:18:06.584 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Input/output error
Jul 26, 2020 23:18:06.584 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvdec
Jul 26, 2020 23:18:06.805 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvenc
Jul 26, 2020 23:18:07.091 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API vaapi
Jul 26, 2020 23:18:07.091 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Input/output error
Jul 26, 2020 23:18:07.091 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvdec
Jul 26, 2020 23:18:07.344 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvenc
Jul 26, 2020 23:18:07.618 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API vaapi
Jul 26, 2020 23:18:07.618 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Input/output error
Jul 26, 2020 23:18:07.618 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvdec
Jul 26, 2020 23:18:07.756 [0x7fb0457fa700] DEBUG - Killing job.
Jul 26, 2020 23:18:07.756 [0x7fb0457fa700] DEBUG - Job was already killed, not killing again.
Jul 26, 2020 23:18:07.756 [0x7fb01effd700] DEBUG - TPU: hardware transcoding: using hardware decode accelerator nvdec
Jul 26, 2020 23:18:07.756 [0x7fb01effd700] DEBUG - TPU: hardware transcoding: zero-copy support present
Jul 26, 2020 23:18:07.757 [0x7fb01effd700] DEBUG - TPU: hardware transcoding: using zero-copy transcoding
Jul 26, 2020 23:18:07.757 [0x7fb01effd700] DEBUG - TPU: hardware transcoding: final decoder: nvdec, final encoder: nvenc
Jul 26, 2020 23:18:07.757 [0x7fb01effd700] DEBUG - Job running: EAE_ROOT='/tmp/pms-64a37f7c-cfd0-4c1d-b95a-a51c7b3c14aa/EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/5f603a2-3204-linux-x86_64/' XDG_CACHE_HOME='/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache' XDG_DATA_HOME='/usr/lib/plexmediaserver/Resources' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' '/usr/lib/plexmediaserver/Plex Transcoder' '-codec:0' 'h264' '-hwaccel:0' 'nvdec' '-hwaccel_fallback_threshold:0' '10' '-hwaccel_output_format:0' 'cuda' '-codec:1' 'ac3' '-analyzeduration' '20000000' '-probesize' '20000000' '-i' '/media/movies/Sintel.2011.1080p.mkv' '-filter_complex' '[0:0]hwupload[0];[0]scale_cuda=w=718:h=306:format=nv12[1]' '-filter_complex' '[0:1] aresample=async=1:ocl='\''stereo'\'':rematrix_maxval=0.000000dB:osr=48000[2]' '-map' '[1]' '-metadata:s:0' 'language=eng' '-codec:0' 'h264_nvenc' '-b:0' '951k' '-maxrate:0' '1268k' '-bufsize:0' '2536k' '-preset:0' 'hp' '-forced-idr:0' '1' '-r:0' '24' '-force_key_frames:0' 'expr:gte(t,0+n_forced*8)' '-map' '[2]' '-metadata:s:1' 'language=eng' '-codec:1' 'aac' '-b:1' '159k' '-f' 'dash' '-seg_duration' '8' '-init_seg_name' 'init-stream$RepresentationID$.m4s' '-media_seg_name' 'chunk-stream$RepresentationID$-$Number%05d$.m4s' '-window_size' '5' '-delete_removed' 'false' '-skip_to_segment' '1' '-time_delta' '0.0625' '-manifest_name' 'http://127.0.0.1:32400/video/:/transcode/session/dt3hl9bgnyvapufb9aj31ho1/a5e3d3ae-d013-45fa-a9f5-08c646a8b260/manifest?X-Plex-Http-Pipeline=infinite' '-avoid_negative_ts' 'disabled' '-map_metadata' '-1' '-map_chapters' '-1' 'dash' '-map' '0:2' '-metadata:s:0' 'language=ger' '-codec:0' 'ass' '-f' 'segment' '-segment_format' 'ass' '-segment_time' '1' '-segment_header_filename' 'sub-header' '-segment_start_number' '0' '-segment_list' 'http://127.0.0.1:32400/video/:/transcode/session/dt3hl9bgnyvapufb9aj31ho1/a5e3d3ae-d013-45fa-a9f5-08c646a8b260/seglist?stream=subtitles&X-Plex-Http-Pipeline=infinite' '-segment_list_type' 'csv' '-segment_list_size' '5' '-segment_list_separate_stream_times' '1' '-segment_format_options' 'ignore_readorder=1' '-segment_list_unfinished' '1' '-fflags' '+flush_packets' 'sub-chunk-%05d' '-start_at_zero' '-copyts' '-vsync' 'cfr' '-y' '-init_hw_device' 'cuda=cuda:' '-hwaccel_device' 'cuda' '-filter_hw_device' 'cuda' '-nostats' '-loglevel' 'quiet' '-loglevel_plex' 'warning' '-progressurl' 'http://127.0.0.1:32400/video/:/transcode/session/dt3hl9bgnyvapufb9aj31ho1/a5e3d3ae-d013-45fa-a9f5-08c646a8b260/progress'                            Jul 26, 2020 23:18:08.008 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvenc
Jul 26, 2020 23:18:08.315 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API vaapi
Jul 26, 2020 23:18:08.315 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Input/output error
Jul 26, 2020 23:18:08.315 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvdec
Jul 26, 2020 23:18:08.622 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvenc
Jul 26, 2020 23:18:08.936 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API vaapi
Jul 26, 2020 23:18:08.936 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Input/output error
Jul 26, 2020 23:18:08.936 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvdec
Jul 26, 2020 23:18:09.232 [0x7fb06b7fe700] DEBUG - Killing job.
Jul 26, 2020 23:18:09.233 [0x7fb06b7fe700] DEBUG - Job was already killed, not killing again.
Jul 26, 2020 23:18:09.288 [0x7fafb1fff700] WARN - Transcode runner appears to have died.
Jul 26, 2020 23:18:09.291 [0x7fb047fff700] WARN - Transcode runner appears to have died.

Do note that the hardware transcoding selection process happens in the same second, but seems to retest the vaapi kernel driver over and over. Finally, the transcoder is killed, usually with -9.

Here is the command I got from the logs that is runnable

EAE_ROOT='/tmp/pms-64a37f7c-cfd0-4c1d-b95a-a51c7b3c14aa/EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/5f603a2-3204-linux-x86_64/' XDG_CACHE_HOME='/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache' XDG_DATA_HOME='/usr/lib/plexmediaserver/Resources' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' '/usr/lib/plexmediaserver/Plex Transcoder' '-codec:0' 'h264' '-hwaccel:0' 'nvdec' '-hwaccel_fallback_threshold:0' '10' '-hwaccel_output_format:0' 'cuda' '-codec:1' 'ac3' '-analyzeduration' '20000000' '-probesize' '20000000' '-i' '/media/movies/Sintel.2011.1080p.mkv' '-filter_complex' '[0:0]hwupload[0];[0]scale_cuda=w=718:h=306:format=nv12[1]' '-filter_complex' '[0:1] aresample=async=1:ocl='\''stereo'\'':rematrix_maxval=0.000000dB:osr=48000[2]' '-map' '[1]' '-metadata:s:0' 'language=eng' '-codec:0' 'h264_nvenc' '-b:0' '951k' '-maxrate:0' '1268k' '-bufsize:0' '2536k' '-preset:0' 'hp' '-forced-idr:0' '1' '-r:0' '24' '-force_key_frames:0' 'expr:gte(t,0+n_forced*8)' '-map' '[2]' '-metadata:s:1' 'language=eng' '-codec:1' 'aac' '-b:1' '159k' '-f' 'dash' '-seg_duration' '8' '-init_seg_name' 'init-stream$RepresentationID$.m4s' '-media_seg_name' 'chunk-stream$RepresentationID$-$Number%05d$.m4s' '-window_size' '5' '-delete_removed' 'false' '-skip_to_segment' '1' '-time_delta' '0.0625' '-avoid_negative_ts' 'disabled' '-map_metadata' '-1' '-map_chapters' '-1' 'dash' '-map' '0:2' '-metadata:s:0' 'language=ger' '-codec:0' 'ass' '-f' 'segment' '-segment_format' 'ass' '-segment_time' '1' '-segment_header_filename' 'sub-header' '-segment_start_number' '0' '-segment_list_separate_stream_times' '1' '-segment_format_options' 'ignore_readorder=1' '-segment_list_unfinished' '1' '-fflags' '+flush_packets' 'sub-chunk-%05d' '-start_at_zero' '-copyts' '-vsync' 'cfr' '-y' '-init_hw_device' 'cuda=cuda:' '-hwaccel_device' 'cuda' '-filter_hw_device' 'cuda' '-nostats' '-loglevel' 'info' '-loglevel_plex' 'warning'

I wish there was a way to force plex to never use vaapi. Xeon X5650 doesn’t even have quicksync. Plex Transcoder did not appreciate when I moved /usr/lib/plexmediaserver/lib/libva-drm.so.2 and /usr/lib/plexmediaserver/lib/libva.so.2 and refused to work at all.

[ChuckPa]

I understand wanting to turn off the testing and specify the encoding directly.

It won’t like when non-matched SO files are pushed into play because the transcoder, and its modules (codecs) are lock-sync’d to PMS

Every way I slice this, it behaves as if the nvidia codecs are not engaging or damaged.

I wish I could see more than this

Jul 26, 2020 23:18:08.315 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Input/output error
Jul 26, 2020 23:18:08.315 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvdec
Jul 26, 2020 23:18:08.622 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvenc
Jul 26, 2020 23:18:08.936 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API vaapi
Jul 26, 2020 23:18:08.936 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Input/output error
Jul 26, 2020 23:18:08.936 [0x7fafcd349700] DEBUG - Codecs: hardware transcoding: testing API nvdec

there are a few sets of logs floating around this thread.

Do you still see this when you start a transcode?

Jul 26, 2020 11:35:15.142 [0x7f8d3bfff700] DEBUG - TPU: hardware transcoding: using hardware decode accelerator nvdec
Jul 26, 2020 11:35:15.142 [0x7f8d3bfff700] DEBUG - [Universal] Using local file path instead of URL: /home/k8s/movies/shwetflix/shwetflix_hbo.mp4
Jul 26, 2020 11:35:15.142 [0x7f8d3bfff700] DEBUG - TPU: hardware transcoding: zero-copy support present
Jul 26, 2020 11:35:15.142 [0x7f8d3bfff700] DEBUG - TPU: hardware transcoding: using zero-copy transcoding
Jul 26, 2020 11:35:15.142 [0x7f8d3bfff700] DEBUG - TPU: hardware transcoding: final decoder: nvdec, final encoder: nvenc

Emphasis on the nvdec and nvenc

At that point, where is the Transcoder Temp directory ?

Please tell me it’s not on a network share where there is no file locking or kernel inotify support?

The “appears to have died” is when it goes to read data before it;s ready. I see that all the time with Dolby audio problems (again inotify failures)

[mcapplbee]

@ChuckPa
The disks are local, mdadm raid 1 mirror. 2x 4TB HDD (totaling 4TB usable) connected to individual SATA ports and they are the only disks on this system.

► cat /proc/mdstat
Personalities : [raid1] [linear] [multipath] [raid0] [raid6] [raid5] [raid4] [raid10]
md0 : active raid1 sda2[3] sdb2[1]
      3906886464 blocks super 1.2 [2/2] [UU]
      bitmap: 1/30 pages [4KB], 65536KB chunk

unused devices: <none>

► df -h | grep md0
/dev/md0        3.6T  3.1T  352G  90% /

It’s a vanilla Ubuntu Server install. Was 18.04, upgraded to 20.04 as part of trying to figure out this issue.

Before I delve into answering your questions in detail, logs-snippets.zip (157.0 KB) taken with all nonessential services disabled (details below attachments). 3 working logs, 2 broken logs.

[Edit: added another snippet not included with the complete logs while I’m thinking about it - android logs - cycled through most of the quality presets and captured plex log output, since that works no matter what]
android-working-log.zip (73.0 KB)

All tests are playing back that 60 second clip from the movie Sintel I sent you earlier since this is a common point of reference and is safe/legal to distribute.

The snippets are gathered using tail -F "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Logs/Plex Media Server.log" | tee -a /tmp/$FILENAME.log
Full, unmodified logs can be found at the bottom of the post.

To answer your questions about network shares:
There are directories shared out via NFS on /media, but that’s for inspecting / copying files to my main PC. The NFS share has been there for years. Regardless, I’ve disabled it for this test and can still reproduce.

There are also samba shares in this directory, but these are not used by Plex (EG: /media/tutorials). The transcoder functions as expected with software transcoding on this setup and always has for 2 years now. The samba shares are new, but did not affect anything as I only shared out 2 directories plex does not have permission to access and is not configured to access. Regardless, I’ve disabled samba and nfs for this test and can still reproduce.

To answer your question about transcoder directories
The transcoder temp directory was set to default (blank), but as part of my debugging, I have changed it to /dev/shm. Same with /tmp, it was part of the mdadm raid-1 mirror, but was changed to tmpfs today as part of testing. No difference, still fails.

$ df -h
Filesystem      Size  Used Avail Use% Mounted on
udev             12G     0   12G   0% /dev
tmpfs           2.4G  2.8M  2.4G   1% /run
/dev/md0        3.6T  3.1T  352G  90% /
tmpfs            12G  8.0K   12G   1% /dev/shm
tmpfs           5.0M     0  5.0M   0% /run/lock
tmpfs            12G     0   12G   0% /sys/fs/cgroup
tmpfs            14G  5.3M   14G   1% /tmp
tmpfs           2.4G     0  2.4G   0% /run/user/1000

To answer your question about system limits
I also hope it’s some simple system thing like inotify watches, but I am aggressively tailing every common system log and watching metrics, EG: journalctl -xekf & tail -F /var/log*, using nmon with disk, memory, cpu on, watch -d -n1 nvidia-smi and watching the Plex logs.

To rule out inotify watch count, I’ve run this bash script:
Output says ~650, which is well below the inotify limit of 8192. I’m pretty sure the linux kernel would complain to the kernel channel of journald if I was hitting some limit.

► cat /proc/sys/fs/inotify/max_user_watches
8192

►./inotify.sh

   INOTIFY
   WATCHER
    COUNT     PID     CMD
----------------------------------------
     590    81733  /usr/lib/plexmediaserver/Plex Media Server
      39        1  /sbin/init
      29    44004  tail -F ./fontconfig.log ./apt/history.log ./apt/term.log ./bootstrap.log ./dist-upgrade/main.log ./dist-upgrade/apt.log
      14      527  /lib/systemd/systemd-udevd
      14    12930  /usr/lib/policykit-1/polkitd --no-debug
       5        1  /sbin/init
       5        1  /sbin/init
       4        1  /sbin/init
       4        1  /sbin/init
       4    12930  /usr/lib/policykit-1/polkitd --no-debug
       3      888  /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only
       3    44290  journalctl -xekf
       2      510  /usr/sbin/blkmapd
       2    14866  tail -F /var/log/syslog
       1      974  /sbin/agetty -o -p -- \u --noclear tty1 linux
       1      919  /lib/systemd/systemd-logind
       1      882  /lib/systemd/systemd-timesyncd
       1      881  /lib/systemd/systemd-resolved
       1        1  /sbin/init
       1        1  /sbin/init
       1     1085  /lib/systemd/systemd --user
       1     1085  /lib/systemd/systemd --user
       1     1085  /lib/systemd/systemd --user

To to rule out possible network share problems, I’ve gone ahead and issued systemctl stop smbd.service && systemctl stop nfs-server. I’ve verified that these disks are not reachable over the network.

These are the only daemons listening on the network

► ss -tnlp
State                 Recv-Q                Send-Q                               Local Address:Port                                  Peer Address:Port                Process
LISTEN                0                     4096                                       0.0.0.0:111                                        0.0.0.0:*                    users:(("rpcbind",pid=880,fd=4),("systemd",pid=1,fd=31))
LISTEN                0                     1024                                     127.0.0.1:32401                                      0.0.0.0:*                    users:(("Plex Media Serv",pid=81733,fd=61))
LISTEN                0                     4096                                     127.0.0.1:46257                                      0.0.0.0:*                    users:(("containerd",pid=924,fd=7))
LISTEN                0                     4096                                 127.0.0.53%lo:53                                         0.0.0.0:*                    users:(("systemd-resolve",pid=881,fd=13))
LISTEN                0                     128                                        0.0.0.0:22                                         0.0.0.0:*                    users:(("sshd",pid=935,fd=3))
LISTEN                0                     128                                      127.0.0.1:32600                                      0.0.0.0:*                    users:(("Plex Tuner Serv",pid=81841,fd=13))
LISTEN                0                     128                                      127.0.0.1:33339                                      0.0.0.0:*                    users:(("Plex Script Hos",pid=81869,fd=4))
LISTEN                0                     128                                      127.0.0.1:45893                                      0.0.0.0:*                    users:(("Plex Script Hos",pid=81768,fd=8))
LISTEN                0                     4096                                          [::]:111                                           [::]:*                    users:(("rpcbind",pid=880,fd=6),("systemd",pid=1,fd=33))
LISTEN                0                     1024                                             *:32400                                            *:*                    users:(("Plex Media Serv",pid=81733,fd=60))
LISTEN                0                     128                                           [::]:22                                            [::]:*                    users:(("sshd",pid=935,fd=4))

Finally, logs-20200727.zip (1.2 MB) , taken from the entire session from start to finish, EG: systemctl stop plexmediaserver && rm Logs/* && systemctl start plexmediaserver - [Do note that the android logs were added after the testing, so they are unfortunately excluded from this set of complete logs.]

[mcapplbee]

I’m sorry to double post @ChuckPa, but I have run out of things to try. I’m considering returning the GPU. I’m able to transcode successfully and without flaw on

• Android
• Roku

Anything web based seems to fail

• Chromecast
• Plex web
• SyncLounge player

[ChuckPa]

Sorry for delay. It’s been a busy day for me.

1. The P2200 not working for you makes NO sense. It’s the same GP106 processor as a GTX 1050 / 1060.
2. It has the same capabilities as per the Nvidia matrix
3. The only thing it doesn’t support are HEVC B Frames.

Faulty card? – possible.

Your call on that.

Here’s the reference we use.

Video Encode and Decode GPU Support Matrix

[mcapplbee]

I understand that you’re busy and I very much appreciate your help. I’m sorry for my impatience, I was just afraid this would get lost.

Did you have a chance to look at those log snippets? I provided much abridged logs of successful web vs unsuccessful transcodes, as well as full logs for the entire testing. When I look through them, I don’t see anything that stands out and I’m at a loss.

I understand the logs are quite large and it’s a big ask, but when you have the time, could you look through them? I’m willing to try anything at this point.

[ChuckPa]

I did get chance to read through.

One thing I do remember seeing (which is here)

Jul 27, 2020 04:09:40.881 [0x7fca217fa700] DEBUG - Selected a foreign audio track: eng
Jul 27, 2020 04:09:40.881 [0x7fca217fa700] DEBUG - Subtitles: Found a candidate subtitle language [eng] for a foreign film
Jul 27, 2020 04:09:40.881 [0x7fca217fa700] DEBUG - Audio Stream: 32352, Subtitle Stream: 32354
Jul 27, 2020 04:09:40.882 [0x7fca217fa700] DEBUG - Activity: registered new activity 2ec9dbf3-32b7-48a0-afd5-8e36

You are trying to use a subtitle. When subtitles are being burned, HW is not active because subtitles can’t be processed in the GPU (no capability in Linux to do so)

What do you get when you attempt without ?