Sync and transcode stops working after first transcode when steam limit set to 1 to match HW

Plex Media Server
,
21

I will make sure and annotate the logs where “I think” stuff is happening will help explain. I think I will send a clean log zip shortly in the meanwhile here is annotated version.

This is annotated log please search for “####” and you will see my comments.

Dec 20, 2022 12:38:52.866 [0x7fca88dc4b38] DEBUG - [Req#3cc/Transcode] TPU: hardware transcoding: final decoder: nvdec, final encoder: nvenc

####
1st movie staring the nvenv/nvdec transcode

Dec 20, 2022 12:38:52.866 [0x7fca88dc4b38] DEBUG - [Req#3cc/Transcode/JobRunner] Job running: CUDA_CACHE_PATH="/config/Library/Application Support/Plex Media Server/Cache/Shaders/CUDA" EAE_ROOT=/tmp/pms-0cd84cb1-a18e-414d-8bed-aa7b49cd4615/EasyAudioEncoder FFMPEG_EXTERNAL_LIBS='/config/Library/Application\ Support/Plex\ Media\ Server/Codecs/583b3e4-4434-linux-x86_64/' X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxx4a06-b57d-99c95eb48884 "/usr/lib/plexmediaserver/Plex Transcoder" -codec:0 hevc -hwaccel:0 nvdec -hwaccel_fallback_threshold:0 10 -threads:0 1 -hwaccel_output_format:0 cuda -hwaccel_device:0 cuda -codec:1 truehd_eae -eae_prefix:1 3f501e3a6d1a7fda3f449c5896fe987714d94dfa_ -codec:2 dca -codec:3 ac3 -analyzeduration 20000000 -probesize 20000000 -i "/net/arabia/Video/English/Movies/Mission Impossible - Fallout (2018)/Mission Impossible Fallout (2018) [HDR] [10bit] [TrueHD Atmos 7.1].mkv" -filter_complex "[0:0]hwupload[0];[0]scale_cuda=w=1276:h=674:format=p010[1];[1]tonemap_cuda=mobius:nv12[2]" -map "[2]" -codec:0 h264_nvenc -b:0 2718k -maxrate:0 3625k -bufsize:0 7250k -preset:0 hq -forced-idr:0 1 -r:0 23.975999999999999 -filter_complex "[0:1] aresample=async=1:ochl='stereo':rematrix_maxval=0.000000dB:osr=48000[3]" -map "[3]" -metadata:s:1 language=eng -codec:1 aac -b:1 123k -filter_complex "[0:2] aresample=async=1:ochl='stereo':rematrix_maxval=0.000000dB:osr=48000[4]" -map "[4]" -metadata:s:2 language=eng -codec:2 aac -b:2 123k -filter_complex "[0:3] aresample=async=1:ochl='stereo':rematrix_maxval=0.000000dB:osr=48000[5]" -map "[5]" -metadata:s:3 language=eng -codec:3 aac -b:3 123k -map 0:4 -metadata:s:4 language=eng -codec:4 text -strict_ts:4 0 -map 0:5 -metadata:s:5 language=eng -codec:5 text -strict_ts:5 0 -f matroska -map_metadata -1 -map_chapters -1 Output.mkv -init_hw_device cuda=cuda: -filter_hw_device cuda -y -nostats -loglevel quiet -loglevel_plex error -progressurl http://127.0.0.1:32400/video/:/transcode/session/3f501e3a6d1a7fda3f449c5896fe987714d94dfa/1b50c58b-0646-4318-b0fa-55108db7f593/progress
Dec 20, 2022 12:38:52.867 [0x7fca88dc4b38] DEBUG - [Req#3cc/Transcode/JobRunner] In directory: "/transcode/Transcode/Sessions/plex-transcode-3f501e3a6d1a7fda3f449c5896fe987714d94dfa-1b50c58b-0646-4318-b0fa-55108db7f593"
Dec 20, 2022 12:38:52.867 [0x7fca88dc4b38] DEBUG - [Req#3cc/Transcode/JobRunner] Jobs: Starting child process with pid 472

Dec 20, 2022 12:40:26.474 [0x7fca897d3b38] DEBUG - [Req#e46/Transcode] Job was already killed, not killing again.

#####
I manually killed the transcode from the ios plex client but selecting and deleting the job.

Dec 20, 2022 12:40:26.474 [0x7fca897d3b38] DEBUG - [Req#e46/Transcode] Stopping transcode session 3f501e3a6d1a7fda3f449c5896fe987714d94dfa
Dec 20, 2022 12:40:26.474 [0x7fca8be02b38] DEBUG - Completed: [192.168.101.117:57712] 200 GET /video/:/transcode/universal/stop?session=3f501e3a6d1a7fda3f449c5896fe987714d94dfa (17 live) TLS GZIP 0ms 195 bytes (pipelined: 14)
Dec 20, 2022 12:40:26.475 [0x7fca897d3b38] DEBUG - [Req#e46/Transcode] Activity: Ended activity 080b52dc-1a3d-4c22-8a8d-599dc067de58.
Dec 20, 2022 12:40:26.476 [0x7fca8c005b38] DEBUG - Activity: updated activity 659cd4a6-8e34-452b-96c4-62fd08cb7fa8 - completed 3.5% - Media download by manojav
Dec 20, 2022 12:40:26.476 [0x7fca8c005b38] DEBUG - [TranscodeOutputStream] Timed out waiting for data
Dec 20, 2022 12:40:26.476 [0x7fca8c005b38] DEBUG - Removed transcode data consumer, active count 1 => 0
Dec 20, 2022 12:40:26.478 [0x7fca86481b38] DEBUG - [TranscodeOutputStream] Input processing thread exited after writing 116129792 bytes, m_closed=1, m_endOfFileReached=0, session->isStopped()=1
Dec 20, 2022 12:40:26.479 [0x7fca8c005b38] DEBUG - Activity: Ended activity 659cd4a6-8e34-452b-96c4-62fd08cb7fa8.
Dec 20, 2022 12:40:26.479 [0x7fca897d3b38] DEBUG - [Req#e46/Transcode] Transcoder: Cleaning old transcode directories.
Dec 20, 2022 12:40:26.480 [0x7fca897d3b38] DEBUG - [Req#e46/Transcode] Transcoder: Cleaning old transcode directory: "/transcode/Transcode/Sessions/plex-transcode-3f501e3a6d1a7fda3f449c5896fe987714d94dfa-1b50c58b-0646-4318-b0fa-55108db7f593"
Dec 20, 2022 12:40:26.480 [0x7fca897d3b38] DEBUG - [Req#e46/Transcode] Whacked session 3f501e3a6d1a7fda3f449c5896fe987714d94dfa, 0 remaining.

#####
This is where the first transcode ENDs



Dec 20, 2022 12:40:26.493 [0x7fca88dc4b38] DEBUG - Request: [192.168.100.1:54154 (Allowed Network (Subnet))] GET /status/sessions/background (16 live) #e2b TLS GZIP Signed-in Token (manojav) (Chrome)

Dec 20, 2022 12:40:36.712 [0x7fca8798db38] DEBUG - [Req#ebd/Transcode] TPU: hardware transcoding: final decoder: nvdec, final encoder: nvenc

####
Final encoder and Start encoding 2nd Job

Dec 20, 2022 12:40:36.713 [0x7fca8798db38] DEBUG - [Req#ebd/Transcode/JobRunner] Job running: CUDA_CACHE_PATH="/config/Library/Application Support/Plex Media Server/Cache/Shaders/CUDA" EAE_ROOT=/tmp/pms-0cd84cb1-a18e-414d-8bed-aa7b49cd4615/EasyAudioEncoder FFMPEG_EXTERNAL_LIBS='/config/Library/Application\ Support/Plex\ Media\ Server/Codecs/583b3e4-4434-linux-x86_64/' X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxx4a06-b57d-99c95eb48884 "/usr/lib/plexmediaserver/Plex Transcoder" -codec:0 hevc -hwaccel:0 nvdec -hwaccel_fallback_threshold:0 10 -threads:0 1 -hwaccel_output_format:0 cuda -hwaccel_device:0 cuda -codec:1 truehd_eae -eae_prefix:1 3f501e3a6d1a7fda3f449c5896fe987714d94dfa_ -codec:2 dca -codec:3 ac3 -analyzeduration 20000000 -probesize 20000000 -i "/net/arabia/Video/English/Movies/Mission Impossible - Fallout (2018)/Mission Impossible Fallout (2018) [HDR] [10bit] [TrueHD Atmos 7.1].mkv" -filter_complex "[0:0]hwupload[0];[0]scale_cuda=w=1276:h=674:format=p010[1];[1]tonemap_cuda=mobius:nv12[2]" -map "[2]" -codec:0 h264_nvenc -b:0 2718k -maxrate:0 3625k -bufsize:0 7250k -preset:0 hq -forced-idr:0 1 -r:0 23.975999999999999 -filter_complex "[0:1] aresample=async=1:ochl='stereo':rematrix_maxval=0.000000dB:osr=48000[3]" -map "[3]" -metadata:s:1 language=eng -codec:1 aac -b:1 123k -filter_complex "[0:2] aresample=async=1:ochl='stereo':rematrix_maxval=0.000000dB:osr=48000[4]" -map "[4]" -metadata:s:2 language=eng -codec:2 aac -b:2 123k -filter_complex "[0:3] aresample=async=1:ochl='stereo':rematrix_maxval=0.000000dB:osr=48000[5]" -map "[5]" -metadata:s:3 language=eng -codec:3 aac -b:3 123k -map 0:4 -metadata:s:4 language=eng -codec:4 text -strict_ts:4 0 -map 0:5 -metadata:s:5 language=eng -codec:5 text -strict_ts:5 0 -f matroska -map_metadata -1 -map_chapters -1 Output.mkv -init_hw_device cuda=cuda: -filter_hw_device cuda -y -nostats -loglevel quiet -loglevel_plex error -progressurl http://127.0.0.1:32400/video/:/transcode/session/3f501e3a6d1a7fda3f449c5896fe987714d94dfa/6842f575-ed69-44c6-bd71-081495944081/progress
Dec 20, 2022 12:40:36.713 [0x7fca8798db38] DEBUG - [Req#ebd/Transcode/JobRunner] In directory: "/transcode/Transcode/Sessions/plex-transcode-3f501e3a6d1a7fda3f449c5896fe987714d94dfa-6842f575-ed69-44c6-bd71-081495944081"
Dec 20, 2022 12:40:36.713 [0x7fca8798db38] DEBUG - [Req#ebd/Transcode/JobRunner] Jobs: Starting child process with pid 548

Dec 20, 2022 12:40:37.205 [0x7fca86481b38] DEBUG - [TranscodeOutputStream] Input processing thread started at offset 0 for -1 bytes.


HERE IS WHERE THE THROTTLE STARTS

Dec 20, 2022 12:40:37.437 [0x7fca893cdb38] DEBUG - [Req#ee9/Transcode/3f501e3a6d1a7fda3f449c5896fe987714d94dfa/6842f575-ed69-44c6-bd71-081495944081] Session 3f501e3a6d1a7fda3f449c5896fe987714d94dfa (0) is throttling
Dec 20, 2022 12:40:37.437 [0x7fca8798db38] DEBUG - [Req#f29/Transcode/3f501e3a6d1a7fda3f449c5896fe987714d94dfa/6842f575-ed69-44c6-bd71-081495944081] Throttle - Going into sloth mode.

AND COMPLETED is now  -1.0% 



Dec 20, 2022 12:40:39.119 [0x7fca8798db38] DEBUG - Request: [192.168.101.117:57712 (Allowed Network (Subnet))] GET /transcode/sessions/3f501e3a6d1a7fda3f449c5896fe987714d94dfa (16 live) #ebc TLS GZIP Signed-in Token (manojav) (iPhone)
22

May I have the ZIP file please. Just one log is tying my hands

23

Yes in ~30 minutes.

24

I will give you a PM so you can send them AS IS in private if you prefer

25

Yes pls.

26

PXL_20221221_003632053
PXL_20221221_003632053943×530 64.8 KB

This works on an individual basis but it is annoying to have to do this for every movie I want to watch.

27

Thanks, my issues are when sycning/download. no issues when playing the movies to various players.

28

@ChuckPa

Here is what I think the issue is

Dec 20, 2022 19:58:05.668 [0x7ff3ad72eb38] DEBUG - [Req#8ef0/Transcode/e63071b820c5eb407238386c10edd49503c82ab8/7e1e4edb-deea-44c2-9054-b50fe5b9b9e6] Streaming Resource: Unthrottling session 0x7ff3b6636488:467333B0-E228-4E1F-8F83-F7DE5E3182FA which is using static transcoder slot.  Used slots is now 2

When I set the throttle from 1 to unlimited it start going again! and I think there is some thing else the like an audio stream or a thumbnail that is being generated and that takes up a transcode slot and is not freed in a timely manner, so the sync is now in sloth mode. so possibly that explains this behavior.

29

Looks like the slots aren’t counted correctly when sync/downloads are going on. I have only 2 downloads in progress and two plex transcoder processes however they are double counted.

Dec 20, 2022 19:46:25.626 [0x7ff3ab0f3b38] DEBUG - [Req#392/Transcode/d33f50b518e8a2cbefe929c53781df559350d48c/ca1e4250-02a4-4757-8b82-ec006640a6ef] Streaming Resource: Unthrottling session 0x7ff3b00bd358:45136302-048E-4B0E-94D5-CCC365D86E42 which is using static transcoder slot.  Used slots is now 1
Dec 20, 2022 19:58:05.668 [0x7ff3ad72eb38] DEBUG - [Req#8ef0/Transcode/e63071b820c5eb407238386c10edd49503c82ab8/7e1e4edb-deea-44c2-9054-b50fe5b9b9e6] Streaming Resource: Unthrottling session 0x7ff3b6636488:467333B0-E228-4E1F-8F83-F7DE5E3182FA which is using static transcoder slot.  Used slots is now 2
Dec 20, 2022 20:03:40.839 [0x7ff3b07f5b38] DEBUG - [Req#da82/Transcode/28b17ca9d26a3550ff7a444c9426af667e9d9570/0bccaf46-db63-4a50-bac4-1286d2f18b36] Streaming Resource: Unthrottling session 0x7ff3b4e0b058:BBC23B55-2BA1-492C-A7A0-4D0C7FCA13D1 which is using static transcoder slot.  Used slots is now 3
Dec 20, 2022 20:04:25.011 [0x7ff3aca80b38] DEBUG - [Req#eb5b/Transcode/f318c10c2fcd91f018165710dd05c5e340a4cb6b/768ccd62-0e78-43ee-87f9-34fde900c95c] Streaming Resource: Unthrottling session 0x7ff3b03a34f8:E9E507DA-23B6-4530-AF3C-FE88E3A7A762 which is using static transcoder slot.  Used slots is now 4

So work around is setting the stream to unlimited, but if you have number of users hitting the download this will cause an issue as you run out of hardware!

30

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.