HW Transcode Not Working / Streams Completely Die When Changing off of Original Quality

[seanmitch]

I have been struggling with this for weeks now, and I am almost certain this issue is across all players, but for simplicity it is likely best we focus on my web browser playback.

Server Version#: 1.24.3.5033
Player Version#: Edge Browser - Plex Web V4.65.1

I have a PMS with 8 cores, 8 GB RAM, and a Tesla P4 for hardware transcoding. Up until 3 weeks ago it was working like a charm and transcoding as expected with the P4 but suddenly and inexplicably this has changed.

Now when trying to stream at any quality other than the original quality the stream will just go to a black screen and will never display any errors like insufficient power, or transcode exited due to an error. EX:

I have tried wiping out all nvidia drivers and reinstalling and according to the output below they are functioning exactly as they should:

“lspci -v” output:
0b:00.0 3D controller: NVIDIA Corporation GP104GL [Tesla P4] (rev a1)
DeviceName: pciPassthru0
Subsystem: NVIDIA Corporation GP104GL [Tesla P4]
Physical Slot: 192
Flags: bus master, fast devsel, latency 248, IRQ 69
Memory at fc000000 (32-bit, non-prefetchable) [size=16M]
Memory at d0000000 (64-bit, prefetchable) [size=256M]
Memory at e4000000 (64-bit, prefetchable) [size=32M]
Capabilities: [60] Power Management version 3
Capabilities: [68] MSI: Enable+ Count=1/1 Maskable- 64bit+
Capabilities: [78] Express Endpoint, MSI 00
Capabilities: [100] Virtual Channel
Capabilities: [128] Power Budgeting <?> Capabilities: [420] Advanced Error Reporting Capabilities: [600] Vendor Specific Information: ID=0001 Rev=1 Len=024 <?>
Capabilities: [900] Secondary PCI Express
Kernel driver in use: nvidia
Kernel modules: nvidiafb, nouveau, nvidia_drm, nvidia

“nvidia-smi” output:

Last bit of information, when I click the convert button, on the plex server in the “nvtop” application (htop for gpus), for a split second I see a plex process attempt to access the GPU but it seems to crash and never attempt to open it again.

[seanmitch]

It appears Automatic quality may work, I believe this is because it automatically chooses CPU and which does work.

[ChuckPa]

Need to see the DEBUG (not VERBOSE) logs which capture the playback.

The logs will show what PMS is seeing and deciding.

[seanmitch]

I noticed in the “Plex Media Server.log” some errors that I have seen before when watching the console and experiencing these issues. I should note these logs were taken within 5 minutes of failed playback and if I had to guess the errors below are the errors from my playback.

Sep 22, 2021 18:30:07.901 [0x7f4456789b38] ERROR - [Transcode] [FFMPEG] - Cannot load libnvidia-encode.so.1
Sep 22, 2021 18:30:07.901 [0x7f4456789b38] ERROR - [Transcode] [FFMPEG] - The minimum required Nvidia driver for nvenc is 418.30 or newer
Sep 22, 2021 18:30:07.928 [0x7f4456789b38] WARN - [Transcode] Codecs: avcodec_open2 returned -1 for encoder 'h264_nvenc'
Sep 22, 2021 18:30:07.928 [0x7f4456789b38] DEBUG - [Transcode] Krill - video.bitrate limitation applies: 11554 > 10000
Sep 22, 2021 18:30:07.928 [0x7f4456789b38] DEBUG - [Transcode] MDE: Cannot direct stream video stream due to profile or setting limitations
Sep 22, 2021 18:30:07.928 [0x7f4456789b38] DEBUG - [Transcode] Codecs: testing h264 (decoder) with hwdevice vaapi
Sep 22, 2021 18:30:07.928 [0x7f4456789b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API vaapi
Sep 22, 2021 18:30:07.928 [0x7f4456789b38] ERROR - [Transcode] [FFMPEG] - libva: vaGetDriverNameByIndex() failed with unknown libva error, driver_name = (null)
Sep 22, 2021 18:30:07.928 [0x7f4456789b38] ERROR - [Transcode] [FFMPEG] - Failed to initialise VAAPI connection: -1 (unknown libva error).
Sep 22, 2021 18:30:07.928 [0x7f4456789b38] DEBUG - [Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: I/O error
Sep 22, 2021 18:30:07.928 [0x7f4456789b38] DEBUG - [Transcode] Codecs: testing h264 (decoder) with hwdevice nvdec
Sep 22, 2021 18:30:07.928 [0x7f4456789b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API nvdec
Sep 22, 2021 18:30:07.928 [0x7f4456789b38] DEBUG - [Transcode] [FFMPEG] - Loaded lib: libcuda.so.1

Plex Media Server Logs_2021-09-22_18-31-22.zip (3.9 MB)

EDIT: Clarity

[seanmitch]

Update! Putting all this info out and really reading over the logs I think I may have fixed it?!?!?! Back when I installed the server drivers with the following command:

sudo apt-get install nvidia-headless-470-server -y

It appears to have missed libnvidia encode and decode as the errors stated.

@seanmitch

Cannot load libnvidia-encode.so.1

Then I looked up how to get that library and found the following command:

sudo apt-get install libnvidia-encode-470-server libnvidia-decode-470-server -y

And now even “nvtop” is showing ENC and DEC stats and the plex process running.

Please let me know if there is anything else I may be missing, I will report back whether or not this has fully resolved the issue as well.

[ChuckPa]

@seanmitch

OOOPS

Sep 22, 2021 18:24:27.806 [0x7f4456637b38] DEBUG - [Transcode] Starting a transcode session iwraoob2ewhh891bgvmdl3mz at offset -1.0 (state=3)
Sep 22, 2021 18:24:27.806 [0x7f4456637b38] ERROR - [Transcode] IsFileWritable: failed to create file '"/plex/TMP/23060489-0220-47b3-9acc-f56dc253ef2b"'
Sep 22, 2021 18:24:27.806 [0x7f4456637b38] WARN - [Transcode] IsDirWritable: directory '"/plex/TMP"' is not writable
Sep 22, 2021 18:24:27.806 [0x7f4456637b38] DEBUG - [Transcode] TPU: hardware transcoding: enabled, but no hardware decode accelerator found
Sep 22, 2021 18:24:27.806 [0x7f4456637b38] DEBUG - [Transcode] [Universal] Using local file path instead of URL: /plex/TV-Shows/The Orville/Season 01/The.Orville.S01E04.If.the.Stars.Should.Appear.REPACK.1080p.AMZN.WEB-DL.DDP5.1.H.264-NTb.mkv
Sep 22, 2021 18:24:27.806 [0x7f4456637b38] DEBUG - [Transcode] TPU: hardware transcoding: final decoder: , final encoder: 
Sep 22, 2021 18:24:27.806 [0x7f4456637b38] ERROR - [Transcode] IsFileWritable: failed to create file '"/plex/TMP/f68e137c-63ec-419d-946e-deba49e1ffa5"'
Sep 22, 2021 18:24:27.806 [0x7f4456637b38] WARN - [Transcode] IsDirWritable: directory '"/plex/TMP"' is not writable

He's dead, Jim

[seanmitch]

Saw that as well and corrected it.

[ChuckPa]

if still not working, please provide updated logs so I can follow it.

[seanmitch]

Looks like it is failing again and suddenly nvtop is missing stats on the encoding/decoding libraries??? But the libraries are still installed??? and I haven’t rebooted or changed anything???

Plex Media Server Logs_2021-09-22_19-51-38.zip (2.8 MB)

I really can not catch a break.

[seanmitch]

Yeah, “lspci -v” and “nvidia-smi” both showing the same output, but per my previous statement you can see nvtop is not reading the ENC and DEC library data like it was before.

[ChuckPa]

Is the driver current ? (perhaps too current / bleeding edge – which does happen)

Plex cannot see the card at all.

What shows in /dev/dri ?

PS: I’m in the process of building a 2690v4 system myself. Should be interesting when I catch up

[seanmitch]

My 2690s are V2s I believe, but I wish you the best with V4s! 8 of them do work very well, but when you have a shared Plex, CPU tends to always become a bottleneck.

OK, I think I am actually ok and now my impatience is clouding my investigating skills…

Peeked into logs and the only errors I saw were to “VAAPI”. I assumed this must be an issue and started hunting it down. After lots of googling, apparently “VAAPI” isn’t used in most (from my reading) of NVIDIA GPUs, its an API for most (from my reading) AMD GPUs, hence why Plex sees the error and immediately starts testing “nv_enc” and “nv_dec” for encoding and decoding substitutions that are NVIDIA based.

I use the term most because I do not wish for my research to be gospel to anyone

Sep 22, 2021 19:57:52.422 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: testing h264_vaapi (encoder)
Sep 22, 2021 19:57:52.423 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API vaapi
Sep 22, 2021 19:57:52.423 [0x7f43dfaa3b38] ERROR - [Transcode] [FFMPEG] - libva: vaGetDriverNameByIndex() failed with unknown libva error, driver_name = (null)
Sep 22, 2021 19:57:52.423 [0x7f43dfaa3b38] ERROR - [Transcode] [FFMPEG] - Failed to initialise VAAPI connection: -1 (unknown libva error).
Sep 22, 2021 19:57:52.423 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: I/O error
Sep 22, 2021 19:57:52.423 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: testing h264_nvenc (encoder)
Sep 22, 2021 19:57:52.423 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API nvenc
...........................................
Sep 22, 2021 19:57:52.958 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: testing h264 (decoder) with hwdevice vaapi
Sep 22, 2021 19:57:52.958 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API vaapi
Sep 22, 2021 19:57:52.958 [0x7f43dfaa3b38] ERROR - [Transcode] [FFMPEG] - libva: vaGetDriverNameByIndex() failed with unknown libva error, driver_name = (null)
Sep 22, 2021 19:57:52.958 [0x7f43dfaa3b38] ERROR - [Transcode] [FFMPEG] - Failed to initialise VAAPI connection: -1 (unknown libva error).
Sep 22, 2021 19:57:52.958 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: I/O error
Sep 22, 2021 19:57:52.958 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: testing h264 (decoder) with hwdevice nvdec
Sep 22, 2021 19:57:52.958 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API nvdec
...........................................
Sep 22, 2021 19:57:53.471 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: Testing with profile 'High'
Sep 22, 2021 19:57:53.496 [0x7f43dfaa3b38] DEBUG - [Transcode] Scaled up video bitrate to 17148Kbps based on 1.500000x fudge factor.
Sep 22, 2021 19:57:53.496 [0x7f43dfaa3b38] DEBUG - [Transcode] MDE: Cannot direct stream audio stream due to codec eac3 when profile only allows aac
Sep 22, 2021 19:57:53.496 [0x7f43dfaa3b38] DEBUG - [Transcode] MDE: The Orville - S1 E8 - Into the Fold: selected media 0 / 9676
Sep 22, 2021 19:57:53.496 [0x7f43dfaa3b38] DEBUG - [Transcode] Streaming Resource: Calculated bandwidth of 8669kbps exceeds bandwidth limit. Changing decision parameters provided by client to fit bandwidth limit of 8000kbps
Sep 22, 2021 19:57:53.496 [0x7f43dfaa3b38] DEBUG - [Transcode] Streaming Resource: Determining preferred transcode encoders through transcode only decision.
Sep 22, 2021 19:57:53.496 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: testing h264_nvenc (encoder)
Sep 22, 2021 19:57:53.497 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API nvenc
...........................................
Sep 22, 2021 19:57:54.037 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: testing h264 (decoder) with hwdevice vaapi
Sep 22, 2021 19:57:54.037 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API vaapi
Sep 22, 2021 19:57:54.037 [0x7f43dfaa3b38] ERROR - [Transcode] [FFMPEG] - libva: vaGetDriverNameByIndex() failed with unknown libva error, driver_name = (null)
Sep 22, 2021 19:57:54.037 [0x7f43dfaa3b38] ERROR - [Transcode] [FFMPEG] - Failed to initialise VAAPI connection: -1 (unknown libva error).
Sep 22, 2021 19:57:54.037 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: I/O error
Sep 22, 2021 19:57:54.037 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: testing h264 (decoder) with hwdevice nvdec
Sep 22, 2021 19:57:54.037 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API nvdec
...........................................
Sep 22, 2021 19:57:54.175 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: Testing with profile 'High'
Sep 22, 2021 19:57:54.201 [0x7f43dfaa3b38] DEBUG - [Transcode] Scaled up video bitrate to 17148Kbps based on 1.500000x fudge factor.
Sep 22, 2021 19:57:54.201 [0x7f43dfaa3b38] DEBUG - [Transcode] Streaming Resource: Reducing playback quality for 7619kbps stream bitrate: video resolution to 1920x1080, audio channels to 2, quality to 8
Sep 22, 2021 19:57:54.201 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: testing h264_nvenc (encoder)
Sep 22, 2021 19:57:54.201 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API nvenc
...........................................
Sep 22, 2021 19:57:54.389 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: testing h264 (decoder) with hwdevice vaapi
Sep 22, 2021 19:57:54.389 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API vaapi
Sep 22, 2021 19:57:54.389 [0x7f43dfaa3b38] ERROR - [Transcode] [FFMPEG] - libva: vaGetDriverNameByIndex() failed with unknown libva error, driver_name = (null)
Sep 22, 2021 19:57:54.389 [0x7f43dfaa3b38] ERROR - [Transcode] [FFMPEG] - Failed to initialise VAAPI connection: -1 (unknown libva error).
Sep 22, 2021 19:57:54.389 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: I/O error
Sep 22, 2021 19:57:54.389 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: testing h264 (decoder) with hwdevice nvdec
Sep 22, 2021 19:57:54.389 [0x7f43dfaa3b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API nvdec

After realizing I was chasing a ghost and this error is somewhat expected, I tried hitting play and just waiting an extra 10 seconds for it to load and it did. I then visited NVTOP and I guess the library stats only show when it is in use as they appeared again.

I assume the delay I was chalking up to another failure is just PMS migrating from a raw/original quality stream to a transcoded one and should be expected. It really is only a delay of like 5 - 10 seconds but with all this troubleshooting the past few weeks, I am impatient.

==============================================================================

TL;DR; I am declaring this fixed, no errors are in the logs that are out of the ordinary and the decoding does work now when I select options other than original (it just takes a second to kick in).

Thank you for the help and for making me think through this more than brute-forcing it!

[ChuckPa]

Depending on the video being done, 5 seconds start (fill that buffer and transport to the player) is NOT a bad time.