Transcode fail for external vobsub (idx+sub)

Server Version#: 1.30.2.6563
Player Version#: web 4.98.2, android tv 9.13.1.37459, android mobile 9.13.1.37459

On playback, when external vobsub is selected, playback failed with transcode error message at PMS.

Jan 17, 2023 23:24:15.471 [0x7ffac089eb38] Error — [Req#8eb30/Transcode/0yteu5f3v8y9rlohqnqm47sh/83caf5fc-038f-4c6f-8ef3-a37c30e8dece] [vobsub @ 0x7f450eea6380] Unable to open /var/packages/PlexMediaServer/shares/PlexMediaServer/AppData/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-0yteu5f3v8y9rlohqnqm47sh-83caf5fc-038f-4c6f-8ef3-a37c30e8dece/temp-0.sub as MPEG subtitles
Jan 17, 2023 23:24:15.472 [0x7ffac089eb38] Error — [Req#8eb34/Transcode/0yteu5f3v8y9rlohqnqm47sh/83caf5fc-038f-4c6f-8ef3-a37c30e8dece] /var/packages/PlexMediaServer/shares/PlexMediaServer/AppData/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-0yteu5f3v8y9rlohqnqm47sh-83caf5fc-038f-4c6f-8ef3-a37c30e8dece/temp-0.idx: No such file or directory
Jan 17, 2023 23:24:15.474 [0x7ffac687fb38] Debug — Jobs: '/volume1/@appstore/PlexMediaServer/Plex Transcoder' exit code for process 20184 is 1 (failure)

Attached is the debug log.
Plex Media Server Logs_2023-01-17_23-27-31.zip (474.8 KB)

1 Like

you turned off DEBUG logging. I can’t see anything.

Nothing is saved by turning it off.

I rechecked Plex Media Server.log in the zip file I posted earlier and I see the debug log in it. One of the failed playback started at Jan 17, 2023 23:24:13.892 and ended with failure at Jan 17, 2023 23:24:15.474

Start

End

Anyway, here’s the new one.
Plex Media Server Logs_2023-01-18_03-47-17.zip (3.1 MB)

I checked the file Plex Media Server.log and I can see the failure logs in it.

Search for /temp-0.sub

Any news on this matter?

This issue seemingly prevents me from using Downloads from Plex on my NAS to my iOS device. Can this please get some attention?

Feb 20, 2023 09:51:58.867 [0x7fe2b4729b38] DEBUG - [Req#42c8/JobRunner] In directory: "/transcode/Transcode/Sessions/plex-transcode-bdc60ca4-4111-4c7b-af5c-823017eaecd3-85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c"
Feb 20, 2023 09:51:58.868 [0x7fe2b4729b38] DEBUG - [Req#42c8/JobRunner] Jobs: Starting child process with pid 3048
Feb 20, 2023 09:51:58.870 [0x7fe2b68f0b38] DEBUG - Request: [127.0.0.1:47990 (Loopback)] PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress?status=startup (10 live) #42e7 Signed-in Token (MyUser) (range: bytes=0-) 
Feb 20, 2023 09:51:58.870 [0x7fe2be2e0b38] DEBUG - Completed: [127.0.0.1:47990] 204 PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress?status=startup (10 live) #42e7 0ms 203 bytes (pipelined: 1) (range: bytes=0-) 
Feb 20, 2023 09:51:58.871 [0x7fe2b5fd8b38] DEBUG - Request: [127.0.0.1:47990 (Loopback)] PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress?status=startup (10 live) #4309 Signed-in Token (MyUser) (range: bytes=0-) 
Feb 20, 2023 09:51:58.871 [0x7fe2be0ddb38] DEBUG - Completed: [127.0.0.1:47990] 204 PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress?status=startup (10 live) #4309 0ms 203 bytes (pipelined: 2) (range: bytes=0-) 
Feb 20, 2023 09:51:58.871 [0x7fe2b492cb38] DEBUG - Request: [127.0.0.1:47990 (Loopback)] PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress?status=opening (10 live) #430a Signed-in Token (MyUser) (range: bytes=0-) 
Feb 20, 2023 09:51:58.871 [0x7fe2be0ddb38] DEBUG - Completed: [127.0.0.1:47990] 204 PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress?status=opening (10 live) #430a 0ms 203 bytes (pipelined: 3) (range: bytes=0-) 
Feb 20, 2023 09:51:58.872 [0x7fe2b68f0b38] DEBUG - Request: [127.0.0.1:47990 (Loopback)] PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress?status=opened (10 live) #430b Signed-in Token (MyUser) (range: bytes=0-) 
Feb 20, 2023 09:51:58.872 [0x7fe2be0ddb38] DEBUG - Completed: [127.0.0.1:47990] 204 PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress?status=opened (10 live) #430b 0ms 203 bytes (pipelined: 4) (range: bytes=0-) 
Feb 20, 2023 09:51:58.872 [0x7fe2b5fd8b38] DEBUG - Request: [127.0.0.1:47990 (Loopback)] PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/stream?index=0&id=0&codec=h264&type=video (10 live) #430c Signed-in Token (MyUser) (range: bytes=0-) 
Feb 20, 2023 09:51:58.872 [0x7fe2be2e0b38] DEBUG - Completed: [127.0.0.1:47990] 200 PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/stream?index=0&id=0&codec=h264&type=video (10 live) #430c 0ms 195 bytes (pipelined: 5) (range: bytes=0-) 
Feb 20, 2023 09:51:58.872 [0x7fe2b492cb38] DEBUG - Request: [127.0.0.1:47990 (Loopback)] PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/stream?index=1&id=0&codec=ac3&type=audio (10 live) #430d Signed-in Token (MyUser) (range: bytes=0-) 
Feb 20, 2023 09:51:58.872 [0x7fe2be0ddb38] DEBUG - Completed: [127.0.0.1:47990] 200 PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/stream?index=1&id=0&codec=ac3&type=audio (10 live) #430d 0ms 195 bytes (pipelined: 6) (range: bytes=0-) 
Feb 20, 2023 09:51:58.872 [0x7fe2b68f0b38] DEBUG - Request: [127.0.0.1:47990 (Loopback)] PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/stream?index=2&id=0&codec=dts&type=audio (10 live) #430e Signed-in Token (MyUser) (range: bytes=0-) 
Feb 20, 2023 09:51:58.873 [0x7fe2be0ddb38] DEBUG - Completed: [127.0.0.1:47990] 200 PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/stream?index=2&id=0&codec=dts&type=audio (10 live) #430e 0ms 195 bytes (pipelined: 7) (range: bytes=0-) 
Feb 20, 2023 09:51:58.893 [0x7fe2b5fd8b38] DEBUG - Request: [127.0.0.1:47990 (Loopback)] PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/streamDetail?index=0&id=0&codec=h264&type=video&profile=High&width=1920&height=1080&interlaced=0&level=41&frameRate=23.976&disp_default=1 (10 live) #430f Signed-in Token (MyUser) (range: bytes=0-) 
Feb 20, 2023 09:51:58.893 [0x7fe2be2e0b38] DEBUG - Completed: [127.0.0.1:47990] 200 PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/streamDetail?index=0&id=0&codec=h264&type=video&profile=High&width=1920&height=1080&interlaced=0&level=41&frameRate=23.976&disp_default=1 (10 live) #430f 0ms 195 bytes (pipelined: 8) (range: bytes=0-) 
Feb 20, 2023 09:51:58.893 [0x7fe2b492cb38] DEBUG - Request: [127.0.0.1:47990 (Loopback)] PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/streamDetail?index=1&id=0&codec=ac3&type=audio&bitrate=192000&language=ger&channels=2&layout=stereo&sampleRate=48000&disp_default=1 (10 live) #4310 Signed-in Token (MyUser) (range: bytes=0-) 
Feb 20, 2023 09:51:58.893 [0x7fe2be2e0b38] DEBUG - Completed: [127.0.0.1:47990] 200 PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/streamDetail?index=1&id=0&codec=ac3&type=audio&bitrate=192000&language=ger&channels=2&layout=stereo&sampleRate=48000&disp_default=1 (10 live) #4310 0ms 195 bytes (pipelined: 9) (range: bytes=0-) 
Feb 20, 2023 09:51:58.893 [0x7fe2b68f0b38] DEBUG - Request: [127.0.0.1:47990 (Loopback)] PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/streamDetail?index=2&id=0&codec=dts&type=audio&bitrate=1536000&profile=DTS&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000&bitDepth=24 (10 live) #4311 Signed-in Token (MyUser) (range: bytes=0-) 
Feb 20, 2023 09:51:58.894 [0x7fe2be0ddb38] DEBUG - Completed: [127.0.0.1:47990] 200 PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress/streamDetail?index=2&id=0&codec=dts&type=audio&bitrate=1536000&profile=DTS&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000&bitDepth=24 (10 live) #4311 0ms 195 bytes (pipelined: 10) (range: bytes=0-) 
Feb 20, 2023 09:51:58.894 [0x7fe2b5fd8b38] DEBUG - Request: [127.0.0.1:47990 (Loopback)] PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress?status=opening (10 live) #4312 Signed-in Token (MyUser) (range: bytes=0-) 
Feb 20, 2023 09:51:58.894 [0x7fe2be2e0b38] DEBUG - Completed: [127.0.0.1:47990] 204 PUT /video/:/transcode/session/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/progress?status=opening (10 live) #4312 0ms 203 bytes (pipelined: 11) (range: bytes=0-) 
Feb 20, 2023 09:51:58.895 [0x7fe2b492cb38] ERROR - [Req#4313/Transcode/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c] [vobsub @ 0x7f275a6499c0] Unable to open /transcode/Transcode/Sessions/plex-transcode-bdc60ca4-4111-4c7b-af5c-823017eaecd3-85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/temp-0.sub as MPEG subtitles
Feb 20, 2023 09:51:58.895 [0x7fe2b68f0b38] ERROR - [Req#4314/Transcode/bdc60ca4-4111-4c7b-af5c-823017eaecd3/85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c] /transcode/Transcode/Sessions/plex-transcode-bdc60ca4-4111-4c7b-af5c-823017eaecd3-85ef9f4b-84ff-42c4-a46a-4df6ed4eab4c/temp-0.idx: No such file or directory
Feb 20, 2023 09:51:58.896 [0x7fe2be520b38] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Transcoder' exit code for process 3048 is 1 (failure)
Feb 20, 2023 09:51:58.896 [0x7fe2b4729b38] DEBUG - [Req#42c8] Using default transcode duration of 120 minutes
Feb 20, 2023 09:51:58.896 [0x7fe2b4729b38] DEBUG - [Req#42c8] Using default transcode duration of 120 minutes
Feb 20, 2023 09:51:58.896 [0x7fe2b4729b38] DEBUG - [Req#42c8] Started session successfully: bdc60ca4-4111-4c7b-af5c-823017eaecd3
Feb 20, 2023 09:51:58.896 [0x7fe2b517db38] DEBUG - Streaming Resource: Terminated session 0x7fe2bb8304f8:bdc60ca4-4111-4c7b-af5c-823017eaecd3 with reason Conversion failed. The transcoder exited due to an error.
Feb 20, 2023 09:51:58.896 [0x7fe2b597eb38] DEBUG - Killing job.
Feb 20, 2023 09:51:58.896 [0x7fe2b597eb38] DEBUG - Signalling job ID 3048 with 9
Feb 20, 2023 09:51:58.896 [0x7fe2b597eb38] DEBUG - Job was already killed, not killing again.

@ChuckPa I am also experiencing the issue.
Permissions are fine on the transcode folder.

Feb 27, 2023 13:16:18.206 [0x1517d9feab38] DEBUG - Request: [xxx.xxx.xxx.xxx:34316 (WAN)] GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/index.m3u8 (9 live) #13f8 TLS GZIP Signed-in
Feb 27, 2023 13:16:18.206 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] Starting a transcode session 9f29d7f8c6d1ed2f-com-plexapp-android at offset -1.0 (state=3)
Feb 27, 2023 13:16:18.207 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] TPU: hardware transcoding: using hardware decode accelerator vaapi
Feb 27, 2023 13:16:18.207 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] TPU: hardware transcoding: zero-copy support present
Feb 27, 2023 13:16:18.207 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] TPU: hardware transcoding: not using zero-copy because subtitle burning is required
Feb 27, 2023 13:16:18.207 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] [Universal] Using local file path instead of URL: /tv/The Fresh Prince of Bel-Air/Season 04/S04E06. Mauvais procès (Will Goes a-Courtin').mkv
Feb 27, 2023 13:16:18.207 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android/HCl#65] HTTP requesting GET http://xxx.xxx.xxx.xxx:32400/library/streams/54688?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Feb 27, 2023 13:16:18.208 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:54202 (Loopback)] GET /library/streams/54688 (9 live) #13c2 GZIP Signed-in Token (OBFUSCATED) (OBFUSCATED)
Feb 27, 2023 13:16:18.210 [0x1517dac7fb38] DEBUG - [Req#13c2] Calculated media file path for path [file:///tv/The%20Fresh%20Prince%20of%20Bel-Air/Season%2004/S04E06.%20Mauvais%20procès%20(Will%20Goes%20a-Courtin').idx]: ["/tv/The Fresh Prince of Bel-Air/Season 04/S04E06. Mauvais procès (Will Goes a-Courtin').idx"]
Feb 27, 2023 13:16:18.210 [0x1517dac7fb38] DEBUG - Content-Length of /tv/The Fresh Prince of Bel-Air/Season 04/S04E06. Mauvais procès (Will Goes a-Courtin').idx is 13710 (of total: 13710).
Feb 27, 2023 13:16:18.211 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54202] 200 GET /library/streams/54688 (9 live) GZIP 3ms 13710 bytes (pipelined: 5)
Feb 27, 2023 13:16:18.211 [0x1517da9f9b38] DEBUG - [HttpClient/HCl#65] HTTP/1.1 (0.0s) 200 response from GET http://xxx.xxx.xxx.xxx:32400/library/streams/54688?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx (reused)
Feb 27, 2023 13:16:18.212 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] Downloaded stream from [http://xxx.xxx.xxx.xxx:32400/library/streams/54688?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx] (codec: idx) to temporary file [/transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6/temp-0.idx]
Feb 27, 2023 13:16:18.212 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] Codecs: hardware transcoding: testing API vaapi
Feb 27, 2023 13:16:18.228 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] TPU: hardware transcoding: final decoder: vaapi, final encoder: vaapi
Feb 27, 2023 13:16:18.229 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android/JobRunner] Job running: FFMPEG_EXTERNAL_LIBS='/config/Library/Application\ Support/Plex\ Media\ Server/Codecs/7e8dc7a-4467-linux-x86_64/' XDG_CACHE_HOME="/config/Library/Application Support/Plex Media Server/Cache" XDG_DATA_HOME=/usr/lib/plexmediaserver/Resources X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxx471c-9793-7e2c0bb9d1fd "/usr/lib/plexmediaserver/Plex Transcoder" -codec:0 h264 -hwaccel:0 vaapi -hwaccel_fallback_threshold:0 10 -hwaccel_device:0 vaapi -analyzeduration 20000000 -probesize 20000000 -i '/tv/The Fresh Prince of Bel-Air/Season 04/S04E06. Mauvais procès (Will Goes a-Courtin'\'').mkv' -analyzeduration 20000000 -probesize 20000000 -i /transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6/temp-0.idx -map_inlineass 1:s:0 -filter_complex '[0:0]scale=w=768:h=576:force_divisible_by=4[0];[0]format=pix_fmts=nv12[1];[1]inlineass=font_scale=1.000000:font_path=/usr/lib/plexmediaserver/Resources/Fonts/NotoSans-Medium.otf:fontconfig_file=/usr/lib/plexmediaserver/Resources/fonts.conf:language=fr:overrides=ScaledBorderAndShadow\\\=yes\\\,FontName\\\=Noto\\\ Sans\\\ Medium\\\,Bold\\\=500\\\,PrimaryColour\\\=&H00FFFFFF\\\,OutlineColour\\\=&H00020713\\\,BackColour\\\=&HCC000000:outline=2.6:shadow=1.7:font_size=54[2];[2]hwupload[3]' -map "[3]" -codec:0 h264_vaapi -b:0 2000k -r:0 25 -force_key_frames:0 "expr:gte(t,n_forced*5)" -map 0:1 -metadata:s:1 language=eng -codec:1 copy -copypriorss:1 0 -segment_format matroska -f ssegment -individual_header_trailer 0 -flags +global_header -segment_header_filename header -segment_time 5 -segment_start_number 0 -segment_copyts 1 -segment_time_delta 0.0625 -segment_list "http://xxx.xxx.xxx.xxx:32400/video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/manifest?X-Plex-Http-Pipeline=infinite" -segment_list_type csv -segment_list_size 5 -segment_list_separate_stream_times 1 -segment_list_unfinished 1 -segment_format_options output_ts_offset=10 -max_delay 5000000 -avoid_negative_ts disabled -map_metadata:g -1 -map_metadata:c -1 -map_chapters -1 "media-%05d.ts" -map 1:s:0 -f null -codec ass nullfile -start_at_zero -copyts -vsync cfr -init_hw_device vaapi=vaapi:/dev/dri/renderD128 -filter_hw_device vaapi -y -nostats -loglevel quiet -loglevel_plex error -progressurl http://xxx.xxx.xxx.xxx:32400/video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress
Feb 27, 2023 13:16:18.229 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android/JobRunner] In directory: "/transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6"
Feb 27, 2023 13:16:18.229 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android/JobRunner] Jobs: Starting child process with pid 802
Feb 27, 2023 13:16:18.236 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=startup (10 live) #13ee Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.236 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 204 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=startup (10 live) 0ms 203 bytes (pipelined: 1) (range: bytes=0-) 
Feb 27, 2023 13:16:18.299 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=startup (10 live) #13fb Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.299 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 204 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=startup (10 live) 0ms 203 bytes (pipelined: 2) (range: bytes=0-) 
Feb 27, 2023 13:16:18.300 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opening (10 live) #13fc Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.300 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 204 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opening (10 live) 0ms 203 bytes (pipelined: 3) (range: bytes=0-) 
Feb 27, 2023 13:16:18.302 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opened (10 live) #13fd Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.302 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 204 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opened (10 live) 0ms 203 bytes (pipelined: 4) (range: bytes=0-) 
Feb 27, 2023 13:16:18.302 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=0&id=0&codec=h264&type=video (10 live) #13fe Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.303 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=0&id=0&codec=h264&type=video (10 live) 0ms 195 bytes (pipelined: 5) (range: bytes=0-) 
Feb 27, 2023 13:16:18.303 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=1&id=0&codec=ac3&type=audio (10 live) #13ff Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.303 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=1&id=0&codec=ac3&type=audio (10 live) 0ms 195 bytes (pipelined: 6) (range: bytes=0-) 
Feb 27, 2023 13:16:18.303 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=2&id=0&codec=ac3&type=audio (10 live) #1400 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.303 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=2&id=0&codec=ac3&type=audio (10 live) 0ms 195 bytes (pipelined: 7) (range: bytes=0-) 
Feb 27, 2023 13:16:18.327 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=0&id=0&codec=h264&type=video&profile=High&width=768&height=576&interlaced=0&level=41&frameRate=25.000&disp_default=1 (10 live) #1401 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.327 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=0&id=0&codec=h264&type=video&profile=High&width=768&height=576&interlaced=0&level=41&frameRate=25.000&disp_default=1 (10 live) 0ms 195 bytes (pipelined: 8) (range: bytes=0-) 
Feb 27, 2023 13:16:18.328 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=1&id=0&codec=ac3&type=audio&bitrate=192000&language=eng&channels=2&layout=stereo&sampleRate=48000 (10 live) #1402 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.328 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=1&id=0&codec=ac3&type=audio&bitrate=192000&language=eng&channels=2&layout=stereo&sampleRate=48000 (10 live) 0ms 195 bytes (pipelined: 9) (range: bytes=0-) 
Feb 27, 2023 13:16:18.328 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=2&id=0&codec=ac3&type=audio&bitrate=192000&language=fre&channels=2&layout=stereo&sampleRate=48000 (10 live) #1403 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.329 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=2&id=0&codec=ac3&type=audio&bitrate=192000&language=fre&channels=2&layout=stereo&sampleRate=48000 (10 live) 0ms 195 bytes (pipelined: 10) (range: bytes=0-) 
Feb 27, 2023 13:16:18.329 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=3&id=0&codec=dvd_subtitle&type=subtitle&language=fre (10 live) #1404 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.329 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=3&id=0&codec=dvd_subtitle&type=subtitle&language=fre (10 live) 0ms 195 bytes (pipelined: 11) (range: bytes=0-) 
Feb 27, 2023 13:16:18.331 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:55154 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opening (10 live) #1405 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:18.331 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:55154] 204 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opening (10 live) 0ms 203 bytes (pipelined: 12) (range: bytes=0-) 
Feb 27, 2023 13:16:18.332 [0x1517dac7fb38] ERROR - [Req#1406/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6] [vobsub @ 0x145fc6d37380] Unable to open /transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6/temp-0.sub as MPEG subtitles
Feb 27, 2023 13:16:18.333 [0x1517dac7fb38] ERROR - [Req#1407/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6] /transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6/temp-0.idx: No such file or directory
Feb 27, 2023 13:16:18.340 [0x1517ddbf9b38] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Transcoder' exit code for process 802 is 1 (failure)
Feb 27, 2023 13:16:26.258 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:34320 (WAN)] GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/index.m3u8 (10 live) #13fa TLS GZIP Signed-in
Feb 27, 2023 13:16:28.230 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] Using default transcode duration of 120 minutes
Feb 27, 2023 13:16:28.230 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] Started session successfully: 9f29d7f8c6d1ed2f-com-plexapp-android
Feb 27, 2023 13:16:28.230 [0x1517d9feab38] DEBUG - [Req#13f8/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] HLS: Building an M3U8 for 7200 total seconds with 5 seconds/segment, target duration of 5.
Feb 27, 2023 13:16:28.230 [0x1517dac7fb38] DEBUG - [Req#13fa/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] HLS: Building an M3U8 for 7200 total seconds with 5 seconds/segment, target duration of 5.
Feb 27, 2023 13:16:28.230 [0x1517d93f1b38] DEBUG - Streaming Resource: Changing client to use software decoding
Feb 27, 2023 13:16:28.230 [0x1517d93f1b38] DEBUG - Found session GUID of 9f29d7f8c6d1ed2f-com-plexapp-android in session start.
Feb 27, 2023 13:16:28.232 [0x1517d93f1b38] DEBUG - TranscodeUniversalRequest: adapting profile with augmentation data: add-limitation(scope=videoCodec&scopeName=h264&type=upperBound&name=video.level&value=61)+add-limitation(scope=videoCodec&scopeName=*&type=upperBound&name=video.width&value=3840&replace=true)+add-limitation(scope=videoCodec&scopeName=*&type=upperBound&name=video.height&value=2160&replace=true)+add-limitation(scope=videoCodec&scopeName=hevc&type=notMatch&name=video.DOVIProfile&value=5)+add-transcode-target(type=videoProfile&context=streaming&protocol=hls&container=mkv&videoCodec=h264,hevc&audioCodec=aac_latm,aac,aac,ac3,alac,dca,eac3,flac,mp1,mp2,mp3,opus,vorbis,wmav1,wmav2,wmalossless,wmapro,wmavoice&subtitleCodec=ass,pgs,subrip,dvd_subtitle,mov_text,vtt,dvb_subtitle&replace=true)+add-transcode-target-settings(type=videoProfile&context=streaming&protocol=hls&CopyMatroskaAttachments=true)+add-limitation(scope=videoAudioCodec&scopeName=aac&type=upperBound&name=audio.channels&value=8&replace=true)+add-transcode-target-audio-codec(type=videoProfile&context=streaming&protocol=hls&audioCodec=mp3)+add-transcode-target-audio-codec(type=videoProfile&context=streaming&protocol=hls&audioCodec=ac3)+add-transcode-target-audio-codec(type=videoProfile&context=streaming&protocol=hls&audioCodec=eac3)+add-transcode-target-audio-codec(type=videoProfile&context=streaming&protocol=hls&audioCodec=dca)+add-transcode-target-audio-codec(type=videoProfile&context=streaming&protocol=hls&audioCodec=opus)+add-limitation(scope=videoCodec&scopeName=*&type=NotMatch&name=video.anamorphic&value=999&replace=true)+add-transcode-target(type=subtitleProfile&context=streaming&protocol=http&container=mkv&subtitleCodec=srt)+append-transcode-target-codec(type=videoProfile&context=streaming&protocol=hls&videoCodec=hevc)+add-limitation(scope=videoCodec&scopeName=hevc&type=Match&name=video.profile&list=main)
Feb 27, 2023 13:16:28.232 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:34316] 200 GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/index.m3u8 (10 live) TLS GZIP 10026ms 3993 bytes (pipelined: 13)
Feb 27, 2023 13:16:28.233 [0x1517d93f1b38] DEBUG - TranscodeUniversalRequest: using augmented profile Android
Feb 27, 2023 13:16:28.233 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:34320] 200 GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/index.m3u8 (9 live) TLS GZIP 1974ms 3993 bytes (pipelined: 1)
Feb 27, 2023 13:16:28.233 [0x1517d93f1b38] DEBUG - Downloading document http://xxx.xxx.xxx.xxx:32400/library/metadata/10613?includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=9f29d7f8c6d1ed2f-com-plexapp-android
Feb 27, 2023 13:16:28.241 [0x1517d93f1b38] DEBUG - [Req#141e] We're going to try to auto-select an audio stream for account 1.
Feb 27, 2023 13:16:28.241 [0x1517d93f1b38] DEBUG - [Req#141e] Selecting best audio stream for part ID 20068 (autoselect: 1 language: en)
Feb 27, 2023 13:16:28.241 [0x1517d93f1b38] DEBUG - [Req#141e] We're going to try to auto-select a subtitle.
Feb 27, 2023 13:16:28.241 [0x1517d93f1b38] DEBUG - [Req#141e] Selected a foreign audio track: en
Feb 27, 2023 13:16:28.241 [0x1517d93f1b38] DEBUG - [Req#141e] Subtitles: Found a candidate subtitle language [fr] for a foreign film
Feb 27, 2023 13:16:28.241 [0x1517d93f1b38] DEBUG - [Req#141e] Subtitles: Found a candidate subtitle that matches our forced / language preference. [fr] [0]. Reason [Prefer sidecar]
Feb 27, 2023 13:16:28.241 [0x1517d93f1b38] DEBUG - [Req#141e] Audio Stream: 54064, Subtitle Stream: 54688
Feb 27, 2023 13:16:28.243 [0x1517d93f1b38] DEBUG - MDE: Selected protocol hls; container: mkv
Feb 27, 2023 13:16:28.243 [0x1517d93f1b38] DEBUG - MDE: analyzing media item 20068
Feb 27, 2023 13:16:28.243 [0x1517d93f1b38] DEBUG - MDE: E6 - Will Goes a-Courtin': Direct Play is disabled
Feb 27, 2023 13:16:28.243 [0x1517d93f1b38] DEBUG - MDE: E6 - Will Goes a-Courtin': media must be transcoded in order to use the hls protocol
Feb 27, 2023 13:16:28.243 [0x1517d93f1b38] DEBUG - MDE: E6 - Will Goes a-Courtin': selected subtitle cannot be converted to a compatible format, burning into video stream
Feb 27, 2023 13:16:28.243 [0x1517d93f1b38] DEBUG - MDE: E6 - Will Goes a-Courtin': avoiding video remux due to burned subtitle stream
Feb 27, 2023 13:16:28.243 [0x1517d93f1b38] DEBUG - MDE: E6 - Will Goes a-Courtin': no remuxable profile found, so video stream will be transcoded
Feb 27, 2023 13:16:28.243 [0x1517d93f1b38] DEBUG - MDE: Cannot direct stream video stream due to profile or setting limitations
Feb 27, 2023 13:16:28.244 [0x1517d93f1b38] DEBUG - MDE: The Fresh Prince of Bel-Air - S4 E6 - Will Goes a-Courtin': selected media 0 / 20068
Feb 27, 2023 13:16:28.244 [0x1517d93f1b38] DEBUG - Streaming Resource: Reached Decision id=10613 codes=(General=1001,Direct play not available; Conversion OK. Direct Play=3000,App cannot direct play this item. Direct play is disabled. Transcode=1001,Direct play not available; Conversion OK.) media=(id=20068 part=(id=20068 decision=transcode container=mkv protocol=hls streams=(Video=(id=54063 decision=transcode bitrate=2147483647 encoder=libx264 width=768 height=576) Audio=(id=54064 decision=copy channels=2 rate=48000) Subtitle=(id=54688 decision=burn languageCode=fra location=embedded))))
Feb 27, 2023 13:16:28.244 [0x1517d93f1b38] DEBUG - Transcode Session: Going to restart at offset 0.000000 with segment number -1
Feb 27, 2023 13:16:28.244 [0x1517d93f1b38] DEBUG - Killing job.
Feb 27, 2023 13:16:28.244 [0x1517d93f1b38] DEBUG - Signalling job ID 802 with 9
Feb 27, 2023 13:16:28.244 [0x1517d93f1b38] DEBUG - Job was already killed, not killing again.
Feb 27, 2023 13:16:28.244 [0x1517d93f1b38] DEBUG - Stopping transcode session 9f29d7f8c6d1ed2f-com-plexapp-android
Feb 27, 2023 13:16:28.244 [0x1517d93f1b38] DEBUG - Starting a transcode session 9f29d7f8c6d1ed2f-com-plexapp-android at offset 0.0 (state=3)
Feb 27, 2023 13:16:28.244 [0x1517d93f1b38] DEBUG - TPU: hardware transcoding: enabled, but no hardware decode accelerator found
Feb 27, 2023 13:16:28.244 [0x1517d93f1b38] DEBUG - [Universal] Using local file path instead of URL: /tv/The Fresh Prince of Bel-Air/Season 04/S04E06. Mauvais procès (Will Goes a-Courtin').mkv
Feb 27, 2023 13:16:28.244 [0x1517d93f1b38] DEBUG - [HCl#66] HTTP requesting GET http://xxx.xxx.xxx.xxx:32400/library/streams/54688?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Feb 27, 2023 13:16:28.245 [0x1517d9feab38] DEBUG - Request: [xxx.xxx.xxx.xxx:54202 (Loopback)] GET /library/streams/54688 (9 live) #13f9 GZIP Signed-in Token (OBFUSCATED) (OBFUSCATED)
Feb 27, 2023 13:16:28.247 [0x1517d9feab38] DEBUG - [Req#13f9] Calculated media file path for path [file:///tv/The%20Fresh%20Prince%20of%20Bel-Air/Season%2004/S04E06.%20Mauvais%20procès%20(Will%20Goes%20a-Courtin').idx]: ["/tv/The Fresh Prince of Bel-Air/Season 04/S04E06. Mauvais procès (Will Goes a-Courtin').idx"]
Feb 27, 2023 13:16:28.247 [0x1517d9feab38] DEBUG - Content-Length of /tv/The Fresh Prince of Bel-Air/Season 04/S04E06. Mauvais procès (Will Goes a-Courtin').idx is 13710 (of total: 13710).
Feb 27, 2023 13:16:28.248 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54202] 200 GET /library/streams/54688 (9 live) GZIP 2ms 13710 bytes (pipelined: 6)
Feb 27, 2023 13:16:28.248 [0x1517da9f9b38] DEBUG - [HttpClient/HCl#66] HTTP/1.1 (0.0s) 200 response from GET http://xxx.xxx.xxx.xxx:32400/library/streams/54688?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx (reused)
Feb 27, 2023 13:16:28.249 [0x1517d93f1b38] DEBUG - Downloaded stream from [http://xxx.xxx.xxx.xxx:32400/library/streams/54688?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx] (codec: idx) to temporary file [/transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6/temp-0.idx]
Feb 27, 2023 13:16:28.249 [0x1517d93f1b38] DEBUG - Codecs: hardware transcoding: testing API vaapi
Feb 27, 2023 13:16:28.266 [0x1517d93f1b38] DEBUG - TPU: hardware transcoding: final decoder: , final encoder: 
Feb 27, 2023 13:16:28.267 [0x1517d93f1b38] DEBUG - [JobRunner] Job running: FFMPEG_EXTERNAL_LIBS='/config/Library/Application\ Support/Plex\ Media\ Server/Codecs/7e8dc7a-4467-linux-x86_64/' XDG_CACHE_HOME="/config/Library/Application Support/Plex Media Server/Cache" XDG_DATA_HOME=/usr/lib/plexmediaserver/Resources X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxx471c-9793-7e2c0bb9d1fd "/usr/lib/plexmediaserver/Plex Transcoder" -codec:0 h264 -analyzeduration 20000000 -probesize 20000000 -i '/tv/The Fresh Prince of Bel-Air/Season 04/S04E06. Mauvais procès (Will Goes a-Courtin'\'').mkv' -analyzeduration 20000000 -probesize 20000000 -i /transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6/temp-0.idx -map_inlineass 1:s:0 -filter_complex '[0:0]scale=w=768:h=576:force_divisible_by=4[0];[0]format=pix_fmts=yuv420p|nv12[1];[1]inlineass=font_scale=1.000000:font_path=/usr/lib/plexmediaserver/Resources/Fonts/NotoSans-Medium.otf:fontconfig_file=/usr/lib/plexmediaserver/Resources/fonts.conf:language=fr:overrides=ScaledBorderAndShadow\\\=yes\\\,FontName\\\=Noto\\\ Sans\\\ Medium\\\,Bold\\\=500\\\,PrimaryColour\\\=&H00FFFFFF\\\,OutlineColour\\\=&H00020713\\\,BackColour\\\=&HCC000000:outline=2.6:shadow=1.7:font_size=54[2]' -map "[2]" -codec:0 libx264 -crf:0 16 -r:0 25 -preset:0 veryfast -x264opts:0 subme=0:me_range=4:rc_lookahead=10:me=dia:no_chroma_me:8x8dct=0:partitions=none -force_key_frames:0 "expr:gte(t,n_forced*5)" -map 0:1 -metadata:s:1 language=eng -codec:1 copy -copypriorss:1 0 -segment_format matroska -f ssegment -individual_header_trailer 0 -flags +global_header -segment_header_filename header -segment_time 5 -segment_start_number 0 -segment_copyts 1 -segment_time_delta 0.0625 -segment_list "http://xxx.xxx.xxx.xxx:32400/video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/manifest?X-Plex-Http-Pipeline=infinite" -segment_list_type csv -segment_list_size 5 -segment_list_separate_stream_times 1 -segment_list_unfinished 1 -segment_format_options output_ts_offset=10 -max_delay 5000000 -avoid_negative_ts disabled -map_metadata:g -1 -map_metadata:c -1 -map_chapters -1 "media-%05d.ts" -map 1:s:0 -f null -codec ass nullfile -start_at_zero -copyts -vsync cfr -init_hw_device vaapi=vaapi:/dev/dri/renderD128 -filter_hw_device vaapi -y -nostats -loglevel quiet -loglevel_plex error -progressurl http://xxx.xxx.xxx.xxx:32400/video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress
Feb 27, 2023 13:16:28.267 [0x1517d93f1b38] DEBUG - [JobRunner] In directory: "/transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6"
Feb 27, 2023 13:16:28.267 [0x1517d93f1b38] DEBUG - [JobRunner] Jobs: Starting child process with pid 814
Feb 27, 2023 13:16:28.267 [0x1517d93f1b38] DEBUG - Started session successfully: 9f29d7f8c6d1ed2f-com-plexapp-android
Feb 27, 2023 13:16:28.274 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=startup (10 live) #140a Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.274 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 204 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=startup (10 live) 0ms 203 bytes (pipelined: 1) (range: bytes=0-) 
Feb 27, 2023 13:16:28.337 [0x1517d9feab38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=startup (10 live) #142b Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.337 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 204 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=startup (10 live) 0ms 203 bytes (pipelined: 2) (range: bytes=0-) 
Feb 27, 2023 13:16:28.337 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opening (10 live) #142c Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.338 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 204 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opening (10 live) 0ms 203 bytes (pipelined: 3) (range: bytes=0-) 
Feb 27, 2023 13:16:28.340 [0x1517d9feab38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opened (10 live) #142d Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.340 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 204 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opened (10 live) 0ms 203 bytes (pipelined: 4) (range: bytes=0-) 
Feb 27, 2023 13:16:28.341 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=0&id=0&codec=h264&type=video (10 live) #142e Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.341 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=0&id=0&codec=h264&type=video (10 live) 0ms 195 bytes (pipelined: 5) (range: bytes=0-) 
Feb 27, 2023 13:16:28.341 [0x1517d9feab38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=1&id=0&codec=ac3&type=audio (10 live) #142f Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.341 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=1&id=0&codec=ac3&type=audio (10 live) 0ms 195 bytes (pipelined: 6) (range: bytes=0-) 
Feb 27, 2023 13:16:28.342 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=2&id=0&codec=ac3&type=audio (10 live) #1430 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.342 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/stream?index=2&id=0&codec=ac3&type=audio (10 live) 0ms 195 bytes (pipelined: 7) (range: bytes=0-) 
Feb 27, 2023 13:16:28.345 [0x1517d9feab38] DEBUG - Request: [xxx.xxx.xxx.xxx:34320 (WAN)] GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/header (10 live) #141d TLS Signed-in
Feb 27, 2023 13:16:28.365 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=0&id=0&codec=h264&type=video&profile=High&width=768&height=576&interlaced=0&level=41&frameRate=25.000&disp_default=1 (10 live) #1431 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.365 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=0&id=0&codec=h264&type=video&profile=High&width=768&height=576&interlaced=0&level=41&frameRate=25.000&disp_default=1 (10 live) 0ms 195 bytes (pipelined: 8) (range: bytes=0-) 
Feb 27, 2023 13:16:28.366 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=1&id=0&codec=ac3&type=audio&bitrate=192000&language=eng&channels=2&layout=stereo&sampleRate=48000 (10 live) #1432 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.366 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=1&id=0&codec=ac3&type=audio&bitrate=192000&language=eng&channels=2&layout=stereo&sampleRate=48000 (10 live) 0ms 195 bytes (pipelined: 9) (range: bytes=0-) 
Feb 27, 2023 13:16:28.366 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=2&id=0&codec=ac3&type=audio&bitrate=192000&language=fre&channels=2&layout=stereo&sampleRate=48000 (10 live) #1433 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.366 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=2&id=0&codec=ac3&type=audio&bitrate=192000&language=fre&channels=2&layout=stereo&sampleRate=48000 (10 live) 0ms 195 bytes (pipelined: 10) (range: bytes=0-) 
Feb 27, 2023 13:16:28.367 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=3&id=0&codec=dvd_subtitle&type=subtitle&language=fre (10 live) #1434 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.367 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 200 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress/streamDetail?index=3&id=0&codec=dvd_subtitle&type=subtitle&language=fre (10 live) 0ms 195 bytes (pipelined: 11) (range: bytes=0-) 
Feb 27, 2023 13:16:28.368 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:54970 (Loopback)] PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opening (10 live) #1435 Signed-in Token (OBFUSCATED) (range: bytes=0-) 
Feb 27, 2023 13:16:28.368 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:54970] 204 PUT /video/:/transcode/session/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6/progress?status=opening (10 live) 0ms 203 bytes (pipelined: 12) (range: bytes=0-) 
Feb 27, 2023 13:16:28.369 [0x1517dac7fb38] ERROR - [Req#1436/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6] [vobsub @ 0x154037eb6a00] Unable to open /transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6/temp-0.sub as MPEG subtitles
Feb 27, 2023 13:16:28.370 [0x1517dac7fb38] ERROR - [Req#1437/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android/c8d6fba5-a544-45c9-8224-ca8520edf5a6] /transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6/temp-0.idx: No such file or directory
Feb 27, 2023 13:16:28.377 [0x1517ddbf9b38] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Transcoder' exit code for process 814 is 1 (failure)
Feb 27, 2023 13:16:28.378 [0x1517d87c6b38] DEBUG - Streaming Resource: Terminating session 0x1517d8d69ad8:9f29d7f8c6d1ed2f-com-plexapp-android which is using transcoder slot.  Used slots is now 0
Feb 27, 2023 13:16:28.378 [0x1517d5fc7b38] DEBUG - Killing job.
Feb 27, 2023 13:16:28.378 [0x1517d5fc7b38] DEBUG - Signalling job ID 814 with 9
Feb 27, 2023 13:16:28.378 [0x1517d5fc7b38] DEBUG - Job was already killed, not killing again.
Feb 27, 2023 13:16:28.378 [0x1517d5fc7b38] DEBUG - Stopping transcode session 9f29d7f8c6d1ed2f-com-plexapp-android
Feb 27, 2023 13:16:28.378 [0x1517da56eb38] DEBUG - Cleaning directory for session 9f29d7f8c6d1ed2f-com-plexapp-android (/transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6)
Feb 27, 2023 13:16:28.378 [0x1517d87c6b38] DEBUG - Streaming Resource: Terminated session 0x1517d8d69ad8:9f29d7f8c6d1ed2f-com-plexapp-android with reason Conversion failed. The transcoder exited due to an error.
Feb 27, 2023 13:16:28.381 [0x1517d5fc7b38] DEBUG - Transcoder: Cleaning old transcode directories.
Feb 27, 2023 13:16:28.382 [0x1517d5fc7b38] DEBUG - Whacked session 9f29d7f8c6d1ed2f-com-plexapp-android, 0 remaining.
Feb 27, 2023 13:16:28.546 [0x1517d9feab38] DEBUG - [Req#141d/Transcode/9f29d7f8c6d1ed2f-com-plexapp-android] Exists("/transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6/header") => 0
Feb 27, 2023 13:16:28.546 [0x1517d9feab38] DEBUG - [Req#141d/Transcode] Cleaning directory for session 9f29d7f8c6d1ed2f-com-plexapp-android (/transcode/Transcode/Sessions/plex-transcode-9f29d7f8c6d1ed2f-com-plexapp-android-c8d6fba5-a544-45c9-8224-ca8520edf5a6)
Feb 27, 2023 13:16:28.546 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:34320] 404 GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/header (9 live) TLS 201ms 288 bytes (pipelined: 2)
Feb 27, 2023 13:16:28.603 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:34320 (WAN)] GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/header (9 live) #1445 TLS Signed-in
Feb 27, 2023 13:16:28.604 [0x1517dd7f3b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:34320] 404 GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/header (9 live) TLS 0ms 288 bytes (pipelined: 3)
Feb 27, 2023 13:16:29.622 [0x1517d9feab38] DEBUG - Request: [xxx.xxx.xxx.xxx:34320 (WAN)] GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/header (9 live) #1446 TLS Signed-in
Feb 27, 2023 13:16:29.622 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:34320] 404 GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/header (9 live) TLS 0ms 288 bytes (pipelined: 4)
Feb 27, 2023 13:16:31.648 [0x1517dac7fb38] DEBUG - Request: [xxx.xxx.xxx.xxx:34320 (WAN)] GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/header (9 live) #1447 TLS Signed-in
Feb 27, 2023 13:16:31.648 [0x1517dd9f6b38] DEBUG - Completed: [xxx.xxx.xxx.xxx:34320] 404 GET /video/:/transcode/universal/session/9f29d7f8c6d1ed2f-com-plexapp-android/base/header (9 live) TLS 0ms 288 bytes (pipelined: 5)
Feb 27, 2023 13:16:31.738 [0x1517d9feab38] DEBUG - Request: [xxx.xxx.xxx.xxx:34320 (WAN)] GET /video/:/transcode/universal/stop?autoAdjustQuality=0&hasMDE=1&location=wan&mediaBufferSize=74944&path=%2Flibrary%2Fmetadata%2F10613&session=9f29d7f8c6d1ed2f-com-plexapp-android (9 live) #1448 TLS GZIP Signed-in Token (OBFUSCATED) (SM-A336B)
Feb 27, 2023 13:16:31.738 [0x1517d9feab38] WARN - [Req#1448/Transcode] Got a request to stop a transcode session without a valid session GUID.

(I had to remove some lines before as there is a 40k characters limit on this forum…)
Full log: plex.log (52.0 KB)

Still an issue, and not just on Synology! This seems to be trivial to fix - Plex is just failing to download the .sub (or .idx) file to the transcode directory, but is then looking for it there:

[10064] ERROR - [Req#56fdab/Transcode/(REMOVED)] [vobsub @ 000002b21ad77640] Unable to open C:\Users\[USER]\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-(REMOVED)\temp-0.sub as MPEG subtitles

I am also having this issue

Can someone give me:

  1. A sample video file
  2. With matching sub and/or idx file

which replicates this problem.

From there, I will test.

I’ve been having this issue on my server, though it’s random and intermittent. Sometimes it will play the first time, sometimes it will fail with a transcode error, and if I try again, it will work fine after one or two tries.

This is on a Plex Server running on TrueNAS, version 1.31.3.6868 and the client I am experiencing it on both Windows 11 and macOS 13.2.1 in version 1.67.1.

Here is an example snippet.

Apr 01, 2023 16:00:58.977 [0x806bcf100] DEBUG - Request: [XXX.XXX.XXX.XXX:3695 (WAN)] GET /video/:/transcode/universal/decision?hasMDE=1&path=%2Flibrary%2Fmetadata%2F7806&mediaIndex=0&partIndex=0&protocol=http&fastSeek=1&directPlay=0&directStream=0&subtitleSize=100&audioBoost=100&location=wan&session=uze1nzxn0kdgexldnlpbkc9x&offset=0&subtitles=auto&copyts=1&Accept-Language=en (46 live) #d82d3 TLS GZIP Signed-in Token (Zzyzx Wolfe) (jaguar.wolfeindustrie.com)
Apr 01, 2023 16:00:58.977 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Found session GUID of uze1nzxn0kdgexldnlpbkc9x in session start.
Apr 01, 2023 16:00:58.977 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] TranscodeUniversalRequest: using profile Plex Desktop
Apr 01, 2023 16:00:58.977 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Downloading document http://127.0.0.1:32400/library/metadata/7806?includeBandwidths=1&offset=0&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=p8oen5qcelr9hjd4p20zs7i0
Apr 01, 2023 16:00:58.982 [0x806bcf100] DEBUG - [Req#d82d3/Transcode/Req#d82d6] We're going to try to auto-select an audio stream for account 1.
Apr 01, 2023 16:00:58.982 [0x806bcf100] DEBUG - [Req#d82d3/Transcode/Req#d82d6] Selecting best audio stream for part ID 196571 (language: en)
Apr 01, 2023 16:00:58.982 [0x806bcf100] DEBUG - [Req#d82d3/Transcode/Req#d82d6] Audio Stream: 553012, Subtitle Stream: 553224
Apr 01, 2023 16:00:58.983 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: testing h264 (decoder) with hwdevice vaapi
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: testing API vaapi
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Generic error in an external library
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Could not create hardware context for h264
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: Selected protocol http; container: mkv
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: analyzing media item 182367
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: Direct Play is disabled
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: no direct play video profile exists for http/mkv/h264
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: no direct play video profile exists for http/mkv/h264/ac3
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: selected sidecar subtitle stream cannot be direct played
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: Direct Streaming is disabled, so video stream will be transcoded
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: no remuxable profile found, so video stream will be transcoded
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: Cannot direct stream video stream due to profile or setting limitations
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: testing h264 (decoder) with hwdevice vaapi
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: testing API vaapi
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Generic error in an external library
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Could not create hardware context for h264
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: Star Trek: Voyager - S2 E12 - Resistance: selected media 0 / 182367
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Streaming Resource: Required bandwidth unknown (media requires deep analysis) Changing decision parameters provided by client to fit bandwidth limit of 20974kbps
Apr 01, 2023 16:00:58.984 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Streaming Resource: Determining preferred transcode encoders through transcode only decision.
Apr 01, 2023 16:00:58.985 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: testing h264 (decoder) with hwdevice vaapi
Apr 01, 2023 16:00:58.985 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: testing API vaapi
Apr 01, 2023 16:00:58.985 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Generic error in an external library
Apr 01, 2023 16:00:58.985 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Could not create hardware context for h264
Apr 01, 2023 16:00:58.985 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: testing h264 (decoder) with hwdevice vaapi
Apr 01, 2023 16:00:58.985 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: testing API vaapi
Apr 01, 2023 16:00:58.985 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Generic error in an external library
Apr 01, 2023 16:00:58.985 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Could not create hardware context for h264
Apr 01, 2023 16:00:58.985 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Streaming Resource: Reducing playback quality for 19975kbps stream bitrate: video resolution to 632x480, audio channels to 6, quality to 99
Apr 01, 2023 16:00:58.985 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: testing h264 (decoder) with hwdevice vaapi
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: testing API vaapi
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Generic error in an external library
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Could not create hardware context for h264
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: Selected protocol http; container: mkv
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: analyzing media item 182367
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: Direct Play is disabled
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: no direct play video profile exists for http/mkv/h264
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: no direct play video profile exists for http/mkv/h264/ac3
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: selected sidecar subtitle stream cannot be direct played
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: Direct Streaming is disabled, so video stream will be transcoded
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: E12 - Resistance: no remuxable profile found, so video stream will be transcoded
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: Cannot direct stream video stream due to profile or setting limitations
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: testing h264 (decoder) with hwdevice vaapi
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: testing API vaapi
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Generic error in an external library
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Could not create hardware context for h264
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] MDE: Star Trek: Voyager - S2 E12 - Resistance: selected media 0 / 182367
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Streaming Resource: Adding session 0x8302ff618:p8oen5qcelr9hjd4p20zs7i0 which is using 3657kbps of WAN bandwidth.  Used is now 10683kbps
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Streaming Resource: Adding session 0x8302ff618:p8oen5qcelr9hjd4p20zs7i0 which is using transcoder slot.  Used slots is now 1
Apr 01, 2023 16:00:58.986 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Streaming Resource: Added session 0x8302ff618:p8oen5qcelr9hjd4p20zs7i0
Apr 01, 2023 16:00:58.987 [0x806bcf100] DEBUG - [Req#d82d3/Transcode] Streaming Resource: Reached Decision id=7806 codes=(General=1001,Direct play not available; Conversion OK. Direct Play=3000,App cannot direct play this item. Direct play is disabled. Transcode=1001,Direct play not available; Conversion OK.) media=(id=182367 part=(id=196571 decision=transcode container=mkv protocol=http streams=(Video=(id=553011 decision=transcode bitrate=3033 encoder=libx264 width=632 height=480) Audio=(id=553012 decision=copy channels=6 rate=48000) Subtitle=(id=553224 decision=transcode bitrate=2147483647 encoder=ass languageCode=eng location=embedded))))
Apr 01, 2023 16:00:58.987 [0x806bcb000] DEBUG - Completed: [XXX.XXX.XXX.XXX:3695] 200 GET /video/:/transcode/universal/decision?hasMDE=1&path=%2Flibrary%2Fmetadata%2F7806&mediaIndex=0&partIndex=0&protocol=http&fastSeek=1&directPlay=0&directStream=0&subtitleSize=100&audioBoost=100&location=wan&session=uze1nzxn0kdgexldnlpbkc9x&offset=0&subtitles=auto&copyts=1&Accept-Language=en (46 live) #d82d3 TLS GZIP 10ms 2193 bytes (pipelined: 5)
Apr 01, 2023 16:00:59.102 [0x806bcf100] DEBUG - Request: [XXX.XXX.XXX.XXX:3685 (WAN)] GET /library/metadata/7806/thumb/1457724170 (46 live) #d82b6 TLS GZIP Signed-in Token (Zzyzx Wolfe) (jaguar.wolfeindustrie.com)
Apr 01, 2023 16:00:59.106 [0x806bcf100] DEBUG - [Req#d82b6] Calculated media file path for path [metadata://posters/tv.plex.agents.series_1d6c654a2c0512a3f4f8ac5f30cc43a6b526e27f]: ["/usr/local/plexdata-plexpass/Plex Media Server/Metadata/TV Shows/a/fb327119dac6310bc5f636c98a82582def1ace5.bundle/Contents/_combined/posters/tv.plex.agents.series_1d6c654a2c0512a3f4f8ac5f30cc43a6b526e27f"]
Apr 01, 2023 16:00:59.106 [0x806bcf100] DEBUG - Content-Length of /usr/local/plexdata-plexpass/Plex Media Server/Metadata/TV Shows/a/fb327119dac6310bc5f636c98a82582def1ace5.bundle/Contents/_combined/posters/tv.plex.agents.series_1d6c654a2c0512a3f4f8ac5f30cc43a6b526e27f is 13698 (of total: 13698).
Apr 01, 2023 16:00:59.107 [0x806ad4b00] DEBUG - Completed: [XXX.XXX.XXX.XXX:3685] 200 GET /library/metadata/7806/thumb/1457724170 (46 live) #d82b6 TLS GZIP 5ms 13698 bytes (pipelined: 4)
Apr 01, 2023 16:00:59.716 [0x806be0b00] DEBUG - Request: [XXX.XXX.XXX.XXX:3691 (WAN)] GET /video/:/transcode/universal/start?hasMDE=1&path=%2Flibrary%2Fmetadata%2F7806&mediaIndex=0&partIndex=0&protocol=http&fastSeek=1&directPlay=0&directStream=0&subtitleSize=100&audioBoost=100&location=wan&session=uze1nzxn0kdgexldnlpbkc9x&offset=0&subtitles=auto&copyts=1&Accept-Language=en (47 live) #d82a9 TLS Signed-in Token (Zzyzx Wolfe) (jaguar.wolfeindustrie.com) (range: bytes=0-) 
Apr 01, 2023 16:00:59.716 [0x806be0b00] DEBUG - [Req#d82a9/Transcode] Found session GUID of uze1nzxn0kdgexldnlpbkc9x in session start.
Apr 01, 2023 16:00:59.716 [0x806be0b00] DEBUG - [Req#d82a9/Transcode] TranscodeUniversalRequest: using profile Plex Desktop
Apr 01, 2023 16:00:59.716 [0x806be0b00] DEBUG - [Req#d82a9/Transcode] Downloading document http://127.0.0.1:32400/library/metadata/7806?checkFiles=1&includeBandwidths=1&offset=0&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=p8oen5qcelr9hjd4p20zs7i0
Apr 01, 2023 16:00:59.722 [0x806be0b00] DEBUG - [Req#d82a9/Transcode/Req#d82db] We're going to try to auto-select an audio stream for account 1.
Apr 01, 2023 16:00:59.722 [0x806be0b00] DEBUG - [Req#d82a9/Transcode/Req#d82db] Selecting best audio stream for part ID 196571 (language: en)
Apr 01, 2023 16:00:59.722 [0x806be0b00] DEBUG - [Req#d82a9/Transcode/Req#d82db] Audio Stream: 553012, Subtitle Stream: 553224
Apr 01, 2023 16:00:59.723 [0x806be0b00] DEBUG - [Req#d82a9/Transcode] Cleaning directory for session uze1nzxn0kdgexldnlpbkc9x ()
Apr 01, 2023 16:00:59.723 [0x806be0b00] DEBUG - [Req#d82a9/Transcode] Starting a transcode session uze1nzxn0kdgexldnlpbkc9x at offset -1.0 (state=3)
Apr 01, 2023 16:00:59.724 [0x806be0b00] DEBUG - [Req#d82a9/Transcode] TPU: hardware transcoding: enabled, but no hardware decode accelerator found
Apr 01, 2023 16:00:59.724 [0x806be0b00] DEBUG - [Req#d82a9/Transcode] [Universal] Using local file path instead of URL: /plexmedia/TV/Star Trek Voyager/Season 2/Star Trek Voyager - S02E12 - Resistance.mkv
Apr 01, 2023 16:00:59.724 [0x806be0b00] DEBUG - [Req#d82a9/Transcode/HCl#a0b] HTTP requesting GET http://127.0.0.1:32400/library/streams/553224?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Apr 01, 2023 16:00:59.724 [0x8091b8600] DEBUG - Request: [127.0.0.1:29517 (Loopback)] GET /library/streams/553224 (47 live) #d82a8 GZIP Signed-in Token (Zzyzx Wolfe) (Red Wolf)
Apr 01, 2023 16:00:59.726 [0x8091b8600] DEBUG - [Req#d82a8] Calculated media file path for path [file:///plexmedia/TV/Star%20Trek%20Voyager/Season%202/Star%20Trek%20Voyager%20-%20S02E12%20-%20Resistance.idx]: ["/plexmedia/TV/Star Trek Voyager/Season 2/Star Trek Voyager - S02E12 - Resistance.idx"]
Apr 01, 2023 16:00:59.726 [0x8091b8600] DEBUG - Content-Length of /plexmedia/TV/Star Trek Voyager/Season 2/Star Trek Voyager - S02E12 - Resistance.idx is 34704 (of total: 34704).
Apr 01, 2023 16:00:59.726 [0x806bcb000] DEBUG - Completed: [127.0.0.1:29517] 200 GET /library/streams/553224 (47 live) #d82a8 GZIP 1ms 34704 bytes (pipelined: 2)
Apr 01, 2023 16:00:59.726 [0x8091b8100] DEBUG - [HttpClient/HCl#a0b] HTTP/1.1 (0.0s) 200 response from GET http://127.0.0.1:32400/library/streams/553224?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx (reused)
Apr 01, 2023 16:00:59.727 [0x806be0b00] DEBUG - [Req#d82a9/Transcode] Downloaded stream from [http://127.0.0.1:32400/library/streams/553224?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx] (codec: idx) to temporary file [/usr/local/plexdata-plexpass/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-uze1nzxn0kdgexldnlpbkc9x-50ddb145-0a13-4054-9278-630caa725e96/temp-0.idx]
Apr 01, 2023 16:00:59.728 [0x806be0b00] DEBUG - [Req#d82a9/Transcode] TPU: hardware transcoding: final decoder: , final encoder: 
Apr 01, 2023 16:00:59.728 [0x806be0b00] DEBUG - [Req#d82a9/Transcode/JobRunner] Job running: FFMPEG_EXTERNAL_LIBS='/usr/local/plexdata-plexpass/Plex\ Media\ Server/Codecs/2584b51-4483-freebsd-x86_64/' X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxx4cf7-84fd-d34fe498075b "/usr/local/share/plexmediaserver-plexpass/Plex Transcoder" -codec:0 h264 -analyzeduration 20000000 -probesize 20000000 -i "/plexmedia/TV/Star Trek Voyager/Season 2/Star Trek Voyager - S02E12 - Resistance.mkv" -analyzeduration 20000000 -probesize 20000000 -i "/usr/local/plexdata-plexpass/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-uze1nzxn0kdgexldnlpbkc9x-50ddb145-0a13-4054-9278-630caa725e96/temp-0.idx" -filter_complex "[0:0]scale=w=632:h=480:force_divisible_by=4[0];[0]format=pix_fmts=yuv420p|nv12[1]" -map "[1]" -metadata:s:0 language=eng -codec:0 libx264 -crf:0 16 -maxrate:0 3033k -bufsize:0 6066k -r:0 23.975999999999999 -preset:0 veryfast -x264opts:0 subme=2:me_range=4:rc_lookahead=20:me=hex -map 0:1 -metadata:s:1 language=eng -codec:1 copy -copypriorss:1 0 -map 1:s:0 -metadata:s:2 language=eng -codec:2 ass -strict_ts:2 0 -map "0:t?" -codec:t copy -f segment -segment_format matroska -segment_format_options live=1 -segment_time 1 -segment_header_filename header -segment_start_number 0 -segment_list "http://127.0.0.1:32400/video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/manifest?X-Plex-Http-Pipeline=infinite" -segment_list_type csv -segment_list_unfinished 1 -segment_list_size 5 -segment_list_separate_stream_times 1 -avoid_negative_ts disabled -map_metadata:g -1 -map_metadata:c -1 -map_chapters -1 "chunk-%05d" -start_at_zero -copyts -y -nostats -loglevel quiet -loglevel_plex error -progressurl http://127.0.0.1:32400/video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress
Apr 01, 2023 16:00:59.728 [0x806be0b00] DEBUG - [Req#d82a9/Transcode/JobRunner] In directory: "/usr/local/plexdata-plexpass/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-uze1nzxn0kdgexldnlpbkc9x-50ddb145-0a13-4054-9278-630caa725e96"
Apr 01, 2023 16:00:59.728 [0x806be0b00] DEBUG - [Req#d82a9/Transcode/JobRunner] Jobs: Starting child process with pid 82700
Apr 01, 2023 16:00:59.735 [0x8091b8600] DEBUG - Request: [127.0.0.1:29519 (Loopback)] PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress?status=startup (48 live) #d82da Signed-in Token (Zzyzx Wolfe) (range: bytes=0-) 
Apr 01, 2023 16:00:59.736 [0x806ad4b00] DEBUG - Completed: [127.0.0.1:29519] 204 PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress?status=startup (48 live) #d82da 0ms 203 bytes (pipelined: 1) (range: bytes=0-) 
Apr 01, 2023 16:00:59.741 [0x8091b8600] DEBUG - Request: [127.0.0.1:29519 (Loopback)] PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress?status=startup (48 live) #d82df Signed-in Token (Zzyzx Wolfe) (range: bytes=0-) 
Apr 01, 2023 16:00:59.741 [0x806bcb000] DEBUG - Completed: [127.0.0.1:29519] 204 PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress?status=startup (48 live) #d82df 0ms 203 bytes (pipelined: 2) (range: bytes=0-) 
Apr 01, 2023 16:00:59.742 [0x8091b8600] DEBUG - Request: [127.0.0.1:29519 (Loopback)] PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress?status=opening (48 live) #d82e0 Signed-in Token (Zzyzx Wolfe) (range: bytes=0-) 
Apr 01, 2023 16:00:59.742 [0x806ad4b00] DEBUG - Completed: [127.0.0.1:29519] 204 PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress?status=opening (48 live) #d82e0 0ms 203 bytes (pipelined: 3) (range: bytes=0-) 
Apr 01, 2023 16:00:59.743 [0x8091b8600] DEBUG - Request: [127.0.0.1:29519 (Loopback)] PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress?status=opened (48 live) #d82e1 Signed-in Token (Zzyzx Wolfe) (range: bytes=0-) 
Apr 01, 2023 16:00:59.743 [0x806bcb000] DEBUG - Completed: [127.0.0.1:29519] 204 PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress?status=opened (48 live) #d82e1 0ms 203 bytes (pipelined: 4) (range: bytes=0-) 
Apr 01, 2023 16:00:59.743 [0x8091b8600] DEBUG - Request: [127.0.0.1:29519 (Loopback)] PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress/stream?index=0&id=0&codec=h264&type=video (48 live) #d82e2 Signed-in Token (Zzyzx Wolfe) (range: bytes=0-) 
Apr 01, 2023 16:00:59.743 [0x806bcb000] DEBUG - Completed: [127.0.0.1:29519] 200 PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress/stream?index=0&id=0&codec=h264&type=video (48 live) #d82e2 0ms 195 bytes (pipelined: 5) (range: bytes=0-) 
Apr 01, 2023 16:00:59.744 [0x8091b8600] DEBUG - Request: [127.0.0.1:29519 (Loopback)] PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress/stream?index=1&id=0&codec=ac3&type=audio (48 live) #d82e3 Signed-in Token (Zzyzx Wolfe) (range: bytes=0-) 
Apr 01, 2023 16:00:59.744 [0x806bcb000] DEBUG - Completed: [127.0.0.1:29519] 200 PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress/stream?index=1&id=0&codec=ac3&type=audio (48 live) #d82e3 0ms 195 bytes (pipelined: 6) (range: bytes=0-) 
Apr 01, 2023 16:00:59.756 [0x8091b8600] DEBUG - Request: [127.0.0.1:29519 (Loopback)] PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress/streamDetail?index=0&id=0&codec=h264&type=video&profile=High&language=eng&width=632&height=480&interlaced=0&sar=1:1&level=31&frameRate=23.976&disp_default=1 (48 live) #d82e4 Signed-in Token (Zzyzx Wolfe) (range: bytes=0-) 
Apr 01, 2023 16:00:59.756 [0x806bcb000] DEBUG - Completed: [127.0.0.1:29519] 200 PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress/streamDetail?index=0&id=0&codec=h264&type=video&profile=High&language=eng&width=632&height=480&interlaced=0&sar=1:1&level=31&frameRate=23.976&disp_default=1 (48 live) #d82e4 0ms 195 bytes (pipelined: 7) (range: bytes=0-) 
Apr 01, 2023 16:00:59.756 [0x8091b8600] DEBUG - Request: [127.0.0.1:29519 (Loopback)] PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress/streamDetail?index=1&id=0&codec=ac3&type=audio&bitrate=448000&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000&disp_default=1 (48 live) #d82e5 Signed-in Token (Zzyzx Wolfe) (range: bytes=0-) 
Apr 01, 2023 16:00:59.756 [0x806bcb000] DEBUG - Completed: [127.0.0.1:29519] 200 PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress/streamDetail?index=1&id=0&codec=ac3&type=audio&bitrate=448000&language=eng&channels=6&layout=5.1%28side%29&sampleRate=48000&disp_default=1 (48 live) #d82e5 0ms 195 bytes (pipelined: 8) (range: bytes=0-) 
Apr 01, 2023 16:00:59.757 [0x8091b8600] DEBUG - Request: [127.0.0.1:29519 (Loopback)] PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress?status=opening (48 live) #d82e6 Signed-in Token (Zzyzx Wolfe) (range: bytes=0-) 
Apr 01, 2023 16:00:59.757 [0x806bcb000] DEBUG - Completed: [127.0.0.1:29519] 204 PUT /video/:/transcode/session/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96/progress?status=opening (48 live) #d82e6 0ms 203 bytes (pipelined: 9) (range: bytes=0-) 
Apr 01, 2023 16:00:59.758 [0x8091b8600] ERROR - [Req#d82e7/Transcode/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96] [vobsub @ 0x802c81000] Unable to open /usr/local/plexdata-plexpass/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-uze1nzxn0kdgexldnlpbkc9x-50ddb145-0a13-4054-9278-630caa725e96/temp-0.sub as MPEG subtitles
Apr 01, 2023 16:00:59.758 [0x8091b8600] ERROR - [Req#d82e8/Transcode/uze1nzxn0kdgexldnlpbkc9x/50ddb145-0a13-4054-9278-630caa725e96] /usr/local/plexdata-plexpass/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-uze1nzxn0kdgexldnlpbkc9x-50ddb145-0a13-4054-9278-630caa725e96/temp-0.idx: No such file or directory
Apr 01, 2023 16:00:59.760 [0x806ad3c00] DEBUG - Jobs: '/usr/local/share/plexmediaserver-plexpass/Plex Transcoder' exit code for process 82700 is 1 (failure)
Apr 01, 2023 16:00:59.761 [0x809c32700] DEBUG - Streaming Resource: Terminating session 0x8302ff618:p8oen5qcelr9hjd4p20zs7i0 which is using 3657kbps of WAN bandwidth.  Used is now 7026kbps
Apr 01, 2023 16:00:59.761 [0x809c32700] DEBUG - Streaming Resource: Terminating session 0x8302ff618:p8oen5qcelr9hjd4p20zs7i0 which is using transcoder slot.  Used slots is now 0
Apr 01, 2023 16:00:59.761 [0x806be0b00] DEBUG - [Req#d82a9/Transcode] Using default transcode duration of 120 minutes
Apr 01, 2023 16:00:59.761 [0x806be0b00] DEBUG - [Req#d82a9/Transcode] Started session successfully: uze1nzxn0kdgexldnlpbkc9x
Apr 01, 2023 16:00:59.761 [0x809c32700] DEBUG - Streaming Resource: Terminated session 0x8302ff618:p8oen5qcelr9hjd4p20zs7i0 with reason Conversion failed. The transcoder exited due to an error.
Apr 01, 2023 16:00:59.761 [0x806be0b00] DEBUG - Content-Length is -1 (of total: -1).
Apr 01, 2023 16:00:59.761 [0x809c2f500] DEBUG - Killing job.
Apr 01, 2023 16:00:59.761 [0x806be0b00] ERROR - [TranscodeOutputStream] Streaming Session 0x8302ff618 appears to have died from under us
Apr 01, 2023 16:00:59.761 [0x809c2f500] DEBUG - Signalling job ID 82700 with 9
Apr 01, 2023 16:00:59.761 [0x806be0b00] DEBUG - Removed transcode data consumer, active count 1 => 0
Apr 01, 2023 16:00:59.761 [0x809c2f500] DEBUG - Job was already killed, not killing again.
Apr 01, 2023 16:00:59.761 [0x809c2f500] DEBUG - Stopping transcode session uze1nzxn0kdgexldnlpbkc9x
Apr 01, 2023 16:00:59.761 [0x809c32700] DEBUG - Cleaning directory for session uze1nzxn0kdgexldnlpbkc9x (/usr/local/plexdata-plexpass/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-uze1nzxn0kdgexldnlpbkc9x-50ddb145-0a13-4054-9278-630caa725e96)
Apr 01, 2023 16:00:59.762 [0x809c2f500] DEBUG - Transcoder: Cleaning old transcode directories.
Apr 01, 2023 16:00:59.762 [0x809c2f500] DEBUG - Whacked session uze1nzxn0kdgexldnlpbkc9x, 0 remaining.
Apr 01, 2023 16:00:59.762 [0x809c2f500] DEBUG - Cleaning directory for session uze1nzxn0kdgexldnlpbkc9x (/usr/local/plexdata-plexpass/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-uze1nzxn0kdgexldnlpbkc9x-50ddb145-0a13-4054-9278-630caa725e96)

How can I send this media file to help?

Is this what I should see ?

Yep! Once it plays, it works fine, but it will randomly fail to start playing (any episode in this series, really) with a transcoder error, as long as subtitles are enabled, even though it normally Direct Streams. It’s very odd, and usually if I dismiss the error and hit play again, it works fine.

I am also having this problem. Please let me know where to send my pms log if you need it. I have debug enabled.

sample:

May 11, 2023 02:38:58.305 [140346604989240] DEBUG - Completed: [127.0.0.1:52728] 204 PUT /video/:/transcode/session/f10f4424b54508f1-com-plexapp-android/2133a668-2af6-4b34-9fa0-77d5ec4e7b8b/progress?status=opening (15 live) #3ba8 0ms 203 bytes (pipelined: 9) (range: bytes=0-) 
May 11, 2023 02:38:58.306 [140346557705016] ERROR - [Req#3bae/Transcode/f10f4424b54508f1-com-plexapp-android/2133a668-2af6-4b34-9fa0-77d5ec4e7b8b] [vobsub @ 0x7f4cb0d38300] Unable to open /config/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-f10f4424b54508f1-com-plexapp-android-2133a668-2af6-4b34-9fa0-77d5ec4e7b8b/temp-0.sub as MPEG subtitles
May 11, 2023 02:38:58.306 [140346557705016] ERROR - [Req#3bb2/Transcode/f10f4424b54508f1-com-plexapp-android/2133a668-2af6-4b34-9fa0-77d5ec4e7b8b] /config/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-f10f4424b54508f1-com-plexapp-android-2133a668-2af6-4b34-9fa0-77d5ec4e7b8b/temp-0.idx: No such file or directory
May 11, 2023 02:38:58.334 [140346607573816] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Transcoder' exit code for process 4234 is 1 (failure)

I just upgraded to PlexMediaServer-1.32.4.7195-7c8f9d3b6-x86_64_DSM6.spk (I was on PlexMediaServer-1.27.1.5916-6b0e31a64-x86_64_DSM6.spk), and I am now getting the same errors for anything that has IDX/SUB files:

Jul 08, 2023 06:04:45.107 [140151628868408] DEBUG - [Req#1ef46/Transcode/JobRunner] In directory: “/volume1/Plex/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-4u49d4jqokigbv1qh3vq9v1a-80b4ca8f-dcef-4c29-89c3-ebd52dff2644”
Jul 08, 2023 06:04:45.108 [140151628868408] DEBUG - [Req#1ef46/Transcode/JobRunner] Jobs: Starting child process with pid 7404

Jul 08, 2023 06:04:45.686 [140151645252408] ERROR - [Req#1ef56/Transcode/4u49d4jqokigbv1qh3vq9v1a/80b4ca8f-dcef-4c29-89c3-ebd52dff2644] [vobsub @ 0x7f73f5f80040] Unable to open /volume1/Plex/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-4u49d4jqokigbv1qh3vq9v1a-80b4ca8f-dcef-4c29-89c3-ebd52dff2644/temp-0.sub as MPEG subtitles
Jul 08, 2023 06:04:45.686 [140151645252408] ERROR - [Req#1ef57/Transcode/4u49d4jqokigbv1qh3vq9v1a/80b4ca8f-dcef-4c29-89c3-ebd52dff2644] /volume1/Plex/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-4u49d4jqokigbv1qh3vq9v1a-80b4ca8f-dcef-4c29-89c3-ebd52dff2644/temp-0.idx: No such file or directory

Jul 08, 2023 06:04:45.689 [140151835552568] DEBUG - Jobs: ‘/volume1/@appstore/Plex Media Server/Plex Transcoder’ exit code for process 7404 is 1 (failure)
Jul 08, 2023 06:04:45.690 [140151622540088] DEBUG - Streaming Resource: Terminating session 0x7f77a1cbbde8:pc0v3c77rmba5rto337tqp5f which is using transcoder slot. Used slots is now 0
Jul 08, 2023 06:04:45.690 [140151622540088] DEBUG - Streaming Resource: Terminated session 0x7f77a1cbbde8:pc0v3c77rmba5rto337tqp5f with reason Conversion failed. The transcoder exited due to an error.

I can send logs, but it seems to be a known issue now for at least a month or two with various users reporting the same issue.

@ChuckPa are there any updates on this?

Also having this issue. Been happening for a few weeks it seems. Anything we can do to fix?

We have had staffing changes (you’re all aware)

Subtitles is the first thing on the to do list for being fixed
I will find out this week when they plan on starting (or maybe finishing :slight_smile: that work.

1 Like

Are there any news to this issue? It’s still present in 1.32.5.7349

Bumping this to avoid the thread closing automatically.

Still present in 1.32.6.7468, even after reboot.

Watching the /dev/shm/Transcode/Sessions folder during an attempt to play, it seems that a temporary folder is created with the correct permissions, and a temp-0.idx file is created insided it (again, with the correct permissions), but no .sub file is created which is the one that Plex is not finding.

Same exact issue popped up for me today. No idea why, the files and directories all have correct permissions, playing with subtitles off works fine.