Transcoding Errors

Server Version#: Version 1.25.5.5492
Player Version#: tested on multiple versions and clients

I’ve been getting a transcoding error very sporadically for a few weeks now on different devices and different servers. The error is very difficult to reproduce.

The log for this looks like this:

Server performance (CPU Ryzen 5900X GPU Quadro P4000) can be ruled out. The error also occurs in Direct Stream (when only audio needs to be transcoded).
There is enough free disk space for transcodes (500GB).

Any ideas?

no ideas anybody?

Sorry I didn’t see this (forum sometimes doesn’t sent notification).

VM or container in use?
Where is the transcoder temp directory? Local? Network?

no worries - thanks for your reply!

i am using container and transcoder temp directory is local.

i tried to delete the Codecs Folder but its still happening. you probably should know on this machine are three instances of plex media servers. every instance has its own transcoder temp directory but there is only one GPU for all of them.

i also mentioned its also happening if its direct stream and transcode is only for audio.

@samuel_oida_icu

Deleting codecs won’t help this. You’re getting transcoding so the codecs are fine.
(won’t even start transcoding without codecs)

Wouldyou please recreate this , with DEBUG logging enabled, and attach the logs?

It’s not possible to see what’s happening from a 5 line snippet

Also,

 and transcode is only for audio.

Is this dolby audio (EAC3, etc)? If so, you’ve probably exceeded the maximum number of notification slots your kernel allows by default (Kernel , not container).

You must count the number of directories being monitored and determine the appropriate value to increase the kernel table to.

This condition can be verified by restarting Plex and downloading the logs after 3 minutes. If you see “No space left on device” then the table is full.

This procedure, (performed on the host), will remedy it.

it is happening on different codecs. i cant really say one codec is a bigger problem then others …

i just checked one top level directory and getting a number of 4393383 which seems to be a lot … i dont really get which top level directories i should check. btw i am not getting the “out of space” message after restarting…

i hope this log helps more:

Mar 16, 2022 14:28:41.661 [0x7f6c669aeb38] DEBUG - Removed transcode data consumer, active count 0 => 0

Mar 16, 2022 14:28:41.720 [0x7f6c5f28db38] DEBUG - Request: [*. * . * . *:33654 (WAN)] GET /video/:/transcode/universal/session/32c99d985cda0779-com-plexapp-android/base/00021.ts (34 live) Signed-in

Mar 16, 2022 14:28:41.720 [0x7f6c5f28db38] DEBUG - [Transcode/32c99d985cda0779-com-plexapp-android] Asked for segment 21 from session.

Mar 16, 2022 14:28:41.720 [0x7f6c5f28db38] DEBUG - [Transcode/32c99d985cda0779-com-plexapp-android] Returning segment 21 from session

Mar 16, 2022 14:28:41.720 [0x7f6c5f28db38] ERROR - Couldn’t find the file to stream: /transcode/Transcode/Sessions/plex-transcode-32c99d985cda0779-com-plexapp-android-78d29781-f888-4835-8366-8a5f90c76559/media-00021.ts

Mar 16, 2022 14:28:41.720 [0x7f6c6698bb38] DEBUG - Completed: [*. * . * . *:33654] 404 GET /video/:/transcode/universal/session/32c99d985cda0779-com-plexapp-android/base/00021.ts (34 live) 0ms 240 bytes

Mar 16, 2022 14:28:41.720 [0x7f6c669aeb38] DEBUG - Removed transcode data consumer, active count 0 => 0

Mar 16, 2022 14:28:41.780 [0x7f6c65aedb38] DEBUG - Request: [*. * . * . *:33655 (WAN)] GET /video/:/transcode/universal/session/32c99d985cda0779-com-plexapp-android/base/00022.ts (34 live) Signed-in

Mar 16, 2022 14:28:41.780 [0x7f6c65aedb38] DEBUG - [Transcode/32c99d985cda0779-com-plexapp-android] Asked for segment 22 from session.

Mar 16, 2022 14:28:41.780 [0x7f6c65aedb38] DEBUG - [Transcode/32c99d985cda0779-com-plexapp-android] Returning segment 22 from session

Mar 16, 2022 14:28:41.780 [0x7f6c65aedb38] ERROR - Couldn’t find the file to stream: /transcode/Transcode/Sessions/plex-transcode-32c99d985cda0779-com-plexapp-android-78d29781-f888-4835-8366-8a5f90c76559/media-00022.ts

Mar 16, 2022 14:28:41.780 [0x7f6c669aeb38] DEBUG - Completed: [*. * . * . *:33655] 404 GET /video/:/transcode/universal/session/32c99d985cda0779-com-plexapp-android/base/00022.ts (34 live) 0ms 240 bytes

Mar 16, 2022 14:28:41.780 [0x7f6c669aeb38] DEBUG - Removed transcode data consumer, active count 0 => 0

Mar 16, 2022 14:28:41.842 [0x7f6c65db2b38] DEBUG - Request: [*. * . * . *:33656 (WAN)] GET /video/:/transcode/universal/session/32c99d985cda0779-com-plexapp-android/base/00023.ts (34 live) Signed-in

Mar 16, 2022 14:28:41.842 [0x7f6c65db2b38] DEBUG - [Transcode/32c99d985cda0779-com-plexapp-android] Asked for segment 23 from session.

Mar 16, 2022 14:28:41.842 [0x7f6c65db2b38] DEBUG - [Transcode/32c99d985cda0779-com-plexapp-android] Returning segment 23 from session

Mar 16, 2022 14:28:41.842 [0x7f6c65db2b38] ERROR - Couldn’t find the file to stream: /transcode/Transcode/Sessions/plex-transcode-32c99d985cda0779-com-plexapp-android-78d29781-f888-4835-8366-8a5f90c76559/media-00023.ts

Mar 16, 2022 14:28:41.842 [0x7f6c6698bb38] DEBUG - Completed: [*. * . * . *:33656] 404 GET /video/:/transcode/universal/session/32c99d985cda0779-com-plexapp-android/base/00023.ts (34 live) 0ms 240 bytes

Mar 16, 2022 14:28:41.842 [0x7f6c669aeb38] DEBUG - Removed transcode data consumer, active count 0 => 0

Mar 16, 2022 14:28:41.887 [0x7f6c64e4cb38] DEBUG - [Transcode] Session 32c99d985cda0779-com-plexapp-android (3) is unthrottling

Mar 16, 2022 14:28:41.887 [0x7f6c65acab38] DEBUG - [Transcoder] Throttle - Getting back to work.

Mar 16, 2022 14:28:41.900 [0x7f6c655e7b38] DEBUG - Request: [*. * . * . *:33657 (WAN)] GET /video/:/transcode/universal/session/32c99d985cda0779-com-plexapp-android/base/00024.ts (34 live) Signed-in

Mar 16, 2022 14:28:41.900 [0x7f6c655e7b38] DEBUG - [Transcode/32c99d985cda0779-com-plexapp-android] Asked for segment 24 from session.

Mar 16, 2022 14:28:41.900 [0x7f6c655e7b38] DEBUG - [Transcode/32c99d985cda0779-com-plexapp-android] Returning segment 24 from session

Mar 16, 2022 14:28:41.900 [0x7f6c655e7b38] ERROR - Couldn’t find the file to stream: /transcode/Transcode/Sessions/plex-transcode-32c99d985cda0779-com-plexapp-android-78d29781-f888-4835-8366-8a5f90c76559/media-00024.ts

Mar 16, 2022 14:28:41.900 [0x7f6c669aeb38] DEBUG - Completed: [*. * . * . *:33657] 404 GET /video/:/transcode/universal/session/32c99d985cda0779-com-plexapp-android/base/00024.ts (34 live) 0ms 240 bytes

Mar 16, 2022 14:28:41.900 [0x7f6c669aeb38] DEBUG - Removed transcode data consumer, active count 0 => 0

Mar 16, 2022 14:28:41.953 [0x7f6c5ebb6b38] DEBUG - Request: [*. * . * . *:33658 (WAN)] GET /video/:/transcode/universal/session/32c99d985cda0779-com-plexapp-android/base/00025.ts (34 live) Signed-in

Mar 16, 2022 14:28:41.953 [0x7f6c5ebb6b38] DEBUG - [Transcode/32c99d985cda0779-com-plexapp-android] Asked for segment 25 from session.

Mar 16, 2022 14:28:41.979 [0x7f6c616f3b38] DEBUG - [Transcode] Transcoder segment range: 0 - 25 (25)

Mar 16, 2022 14:28:41.979 [0x7f6c616f3b38] ERROR - [Transcode] Failed to calculate available disk space for path ‘“/transcode/Transcode/Sessions/plex-transcode-32c99d985cda0779-com-plexapp-android-78d29781-f888-4835-8366-8a5f90c76559”’: 2 (No such file or directory)

Mar 16, 2022 14:28:41.980 [0x7f6c5f28db38] ERROR - [Transcoder] [stream_segment,ssegment @ 0x7f3e9d272040] Failed to open segment ‘media-00026.ts’

Mar 16, 2022 14:28:41.981 [0x7f6c65aedb38] ERROR - [Transcoder] av_interleaved_write_frame(): No such file or directory

Mar 16, 2022 14:28:41.982 [0x7f6c5f2b0b38] ERROR - [Transcoder] Error writing trailer of media-%05d.ts: Invalid argument

Mar 16, 2022 14:28:41.986 [0x7f6c679f8b38] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 11087 is 1 (failure)

Mar 16, 2022 14:28:41.986 [0x7f6c6620eb38] DEBUG - Streaming Resource: Terminating session 0x7f6c66ce6678:32c99d985cda0779-com-plexapp-android which is using 11659kbps of WAN bandwidth. Used is now 0kbps

Mar 16, 2022 14:28:41.986 [0x7f6c6629ab38] DEBUG - Killing job.

Mar 16, 2022 14:28:41.986 [0x7f6c6629ab38] DEBUG - Signalling job ID 11087 with 9

Mar 16, 2022 14:28:41.986 [0x7f6c6629ab38] DEBUG - Job was already killed, not killing again.

Mar 16, 2022 14:28:41.986 [0x7f6c6629ab38] DEBUG - Stopping transcode session 32c99d985cda0779-com-plexapp-android

Mar 16, 2022 14:28:41.987 [0x7f6c6620eb38] DEBUG - Streaming Resource: Terminated session 0x7f6c66ce6678:32c99d985cda0779-com-plexapp-android with reason Conversion failed. The transcoder exited due to an error.

Mar 16, 2022 14:28:41.993 [0x7f6c6629ab38] DEBUG - Whacked session 32c99d985cda0779-com-plexapp-android, 1 remaining.

Mar 16, 2022 14:28:42.025 [0x7f6c64e4cb38] DEBUG - Request: [*. * . * . *:61715 (WAN)] GET /status/sessions (33 live) TLS GZIP Signed-in Token (okcool-01) (Opera)

Mar 16, 2022 14:28:42.025 [0x7f6c64e4cb38] DEBUG - [Now] Adding 2 sessions.

Mar 16, 2022 14:28:42.025 [0x7f6c65acab38] DEBUG - Request: [*. * . * . *:60394 (WAN)] GET /status/sessions (33 live) GZIP Signed-in Token (okcool-01) (Safari)

Mar 16, 2022 14:28:42.025 [0x7f6c65acab38] DEBUG - [Now] Adding 2 sessions.

Mar 16, 2022 14:28:42.026 [0x7f6c6698bb38] DEBUG - Completed: [*. * . * . *:61715] 200 GET /status/sessions (33 live) TLS GZIP 0ms 3448 bytes (pipelined: 240)

Mar 16, 2022 14:28:42.026 [0x7f6c669aeb38] DEBUG - Completed: [*. * . * . *:60394] 200 GET /status/sessions (33 live) GZIP 0ms 3323 bytes (pipelined: 23)

Mar 16, 2022 14:28:42.053 [0x7f6c5ebb6b38] WARN - [Transcode/32c99d985cda0779-com-plexapp-android] Transcode runner appears to have died.

Mar 16, 2022 14:28:42.053 [0x7f6c5ebb6b38] DEBUG - [Transcode/32c99d985cda0779-com-plexapp-android] Session was stopped.

Mar 16, 2022 14:28:42.053 [0x7f6c66254b38] DEBUG - [Transcode/32c99d985cda0779-com-plexapp-android] Cleaning directory for session 32c99d985cda0779-com-plexapp-android (/transcode/Transcode/Sessions/plex-transcode-32c99d985cda0779-com-plexapp-android-78d29781-f888-4835-8366-8a5f90c76559)

@samuel_oida_icu

I have multiple media directories under my top level.

[chuck@lizum media.2013]$ cd /mnt/media
[chuck@lizum media.2014]$ find ./tv* ./movie* ./*music* ./uhd ./animated  -type d -print | wc -l
5163
[chuck@lizum media.2015]$

In my case, I don’t need worry.

For you, perform the same check as I did above (adjusting pathnames to match your configuration)

Next time you test, Please add the ZIP file. Again, I cannot diagnose from a failing snippet – mid failure

Plex Media Server Logs_2022-03-16_15-29-33.zip (4.4 MB)
i hope you can work better with this

One final request. I understand, based on the activity I see, if you can’t complete this until later.

I request:

  1. Restart Plex
  2. Wait 3 minutes
  3. Download the logs ZIP file.

I ask because what you have shown me here is solid.

I see playback.

I see the Nvidia engage properly and stream as it should.

I see a clean, player-initiated, stop.

Plex Media Server Logs_2022-03-16_21-24-44.zip (6.1 MB)
this is the log 3 minutes after restarting the server (container)

are you sure the log at around 14:28:40 is a clean stop? i am asking because i am always getting this when a user gets these transcode errors.

Did you recreate/update the container?

PMS log #5 shows 1.25.6
PMS log #1->#4 shows 1.25.7

I have not tested with 1.25.7 (I’ll need a few minutes to see what changed)

yes i have updated in the meantime … sorry for that

Here are a few little scripts i run when I want to see more of what the transcoder is doing.

  1. DEBUG mode (helps us now)
[chuck@lizum Downloads.2007]$ cat ../bin/set-transcoder-debug 
#!/bin/sh
Token="$(cat "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Preferences.xml" | tail -1 | sed -e 's/.*PlexOnlineToken="//' | sed -e 's/".*//')"
curl http://127.0.0.1:32400/:/prefs/set\?TranscoderLogLevel=debug\&X-Plex-Token=$Token
[chuck@lizum Downloads.2008]$
  1. Return to normal mode
[chuck@lizum Downloads.2008]$ cat ../bin/set-transcoder-error 
#!/bin/sh
Token="$(cat "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Preferences.xml" | tail -1 | sed -e 's/.*PlexOnlineToken="//' | sed -e 's/".*//')"
curl http://127.0.0.1:32400/:/prefs/set\?TranscoderLogLevel=error\&X-Plex-Token=$Token
[chuck@lizum Downloads.2009]$ 
  1. Change the IP address to that of your server
  2. clear out the obvious shell prompts & save
  3. Enable DEBUG logging of the transcoder.
  4. Restart PMS
  5. Do that playback again and stop after failure.
  6. Download the logs ZIP “one mo’ time” :wink:

I’m looking for the MDE output which I’m not yet seeing.

okay, this will need some time since its not easy to reproduce this issue

However you wish. You can set DEBUG on without harm.
The logs will generate a bit more output but still always rollover / roll off per the rules.

Care to try it with this file?

doesnt help since files they getting an error does transcode properly the other time :smiley:

i got it … please have a look at timestamp 11:27:XX
Plex Media Server Logs_2022-03-17_11-14-47.zip (6.5 MB)

@samuel_oida_icu

Are you certain of the time?

Mar 17, 2022 11:14:45.631 [0x7f2afe307b38] DEBUG - Photo transcoder: Request for url [/library/metadata/399719/thumb/1633649177?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx] (is local: 1 upscaled: 1)
Mar 17, 2022 11:14:45.632 [0x7f2afe307b38] DEBUG - The cache file did not exist, but the original did [/config/Library/Application Support/Plex Media Server/Cache/PhotoTranscoder/4b/4bc4ede62aefbbf1f0ebd67ecdf50c2f3b39114b.jpg].
Mar 17, 2022 11:14:45.654 [0x7f2adf337b38] DEBUG - Created thumbnail of size 480x720, has pixels: 1
Mar 17, 2022 11:14:45.667 [0x7f2b007c0b38] DEBUG - Completed: [192.168.1.111:64084] 200 GET /photo/:/transcode?width=480&height=720&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F399721%2Fthumb%2F1633649262%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (16 live) GZIP 116ms 77288 bytes (pipelined: 33)
Mar 17, 2022 11:14:45.668 [0x7f2afe307b38] DEBUG - Created thumbnail of size 480x720, has pixels: 1
Mar 17, 2022 11:14:45.680 [0x7f2b007e3b38] DEBUG - Completed: [192.168.1.111:64083] 200 GET /photo/:/transcode?width=480&height=720&minSize=1&upscale=1&url=%2Flibrary%2Fmetadata%2F399719%2Fthumb%2F1633649177%3FX-Plex-Token%3Dxxxxxxxxxxxxxxxxxxxx (15 live) GZIP 48ms 64956 bytes (pipelined: 33)
Mar 17, 2022 11:14:45.782 [0x7f2afefc8b38] DEBUG - Request: [192.168.1.111:64102 (WAN)] GET /diagnostics/logs (15 live) GZIP Signed-in Token (okcool-test) (Safari)
Mar 17, 2022 11:14:45.782 [0x7f2afefc8b38] DEBUG - Diagnostics: Building logfile zip

These logs were gathered at 11:14:45

Be advised: I do not see HW encoding

Mar 17, 2022 04:38:10.085 [0x7f2b0041ab38] WARN - MDE: unable to find a working transcode profile for video stream
Mar 17, 2022 04:38:10.085 [0x7f2b0041ab38] WARN - MDE: unable to find a working transcode profile for video stream
Mar 17, 2022 04:38:10.085 [0x7f2b0041ab38] DEBUG - Cleaning directory for session dc775436-1ac0-4c68-bb88-ae9580615061 ()
Mar 17, 2022 04:38:10.085 [0x7f2b0041ab38] DEBUG - Starting a transcode session dc775436-1ac0-4c68-bb88-ae9580615061 at offset -1.0 (state=3)
Mar 17, 2022 04:38:10.085 [0x7f2b0041ab38] DEBUG - Streaming Resource: Added session 0x7f2affbb7998:dc775436-1ac0-4c68-bb88-ae9580615061
Mar 17, 2022 04:38:10.085 [0x7f2b0041ab38] DEBUG - [Universal] Using local file path instead of URL: /mnt/okc-ger-tv/Series/Star Trek - The Next Generation (1987) [tvdbid-71470]/Season 04/Star Trek - The Next Generation - S04E22 - Half a Life [x264-Bluray-1080p AC3-2.0].mkv
Mar 17, 2022 04:38:10.085 [0x7f2b0041ab38] DEBUG - TPU: hardware transcoding: final decoder: , final encoder: 
Mar 17, 2022 04:38:10.086 [0x7f2b0041ab38] DEBUG - [JobRunner] Job running: FFMPEG_EXTERNAL_LIBS='/config/Library/Application\ Support/Plex\ Media\ Server/Codecs/62cc2bc-4261-linux-x86_64/' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' '/usr/lib/plexmediaserver/Plex Transcoder' '-codec:1' 'ac3' '-analyzeduration' '20000000' '-probesize' '20000000' '-i' '/mnt/okc-ger-tv/Series/Star Trek - The Next Generation (1987) [tvdbid-71470]/Season 04/Star Trek - The Next Generation - S04E22 - Half a Life [x264-Bluray-1080p AC3-2.0].mkv' '-filter_complex' '[0:1] aresample=async=1:ocl='\''stereo'\'':rematrix_maxval=0.000000dB:osr=48000[0]' '-map' '[0]' '-metadata:s:0' 'language=deu' '-codec:0' 'flac' '-b:0' '4096k' '-f' 'flac' '-map_metadata' '-1' '-map_chapters' '-1' '-t' '1382.384' '/transcode/Transcode/Detection/ac2caa6f-7a5a-43e5-ac6e-c97ee3e4e742' '-y' '-nostats' '-loglevel' 'quiet' '-loglevel_plex' 'debug' '-progressurl' 'http://127.0.0.1:32400/video/:/transcode/session/dc775436-1ac0-4c68-bb88-ae9580615061/7a1a4631-b034-457b-aff3-7a9920474754/progress'