HDR Tonemapping with Hardware Transcoding Broken PMS 1.29.2.6364

Plex Media Server NAS & Devices
,
1

Server Version#: 1.29.2.6364
Player Version#: 4.87.2

I’ve just setup hardware transcoding (i7-7700 Quick Sync) for my Plex Media Server running in a TrueNAS jail, however HDR tonemapping appears to be broken resulting in “Error code: s1003 (Network)” when starting playback.

TrueNAS version is: 13.0-U3 & the jail running plexmediaserver_plexpass is: 13.1-RELEASE-p3.

Disabling HDR Tonemapping in PMS allows hw transcoding to work as intended however enabling HDR Tonemapping causes the above mentioned playback error.

This is consistent amoung all movies tested despite multiple jail and TrueNAS reboots.

Please can I have some assistance?

Thanks

1 Like
2

Seconded, plex jail locks-up/crashes when trying to hw transcode.

3

Same issue here.

Player: 1.57.1.3358-5fd2a504 (Windows)
Server: 1.29.2.6364

Running on unraid 6.11.5 with i3-12100T (using quicksync) in docker using the official plexinc container image.

Also tested with 1.30.0.6359 resulting in the same issue. SDR 1080p or 4k Content can be hw transcoded just fine. HDR content doesn’t. Plex will fallback to SW transcoding on my machine.

It looks like the issue we had with 1.28.1 until 1.29.1. When disabling “Use hardware-accelerated video encoding” but leave “Use hardware acceleration when available” it works half-way. It does hw transcode the video, but keeps doing the tonemapping via SW (tested via Tautulli which should show “(hw)” twice in the activity status)

4

Player: 1.59.1.3398-dab42972 (Mac)
Server: 1.30.0.6486 (docker)

Been having the HDR tone mapping issue since 1.29.x. Upgraded today to 1.30.0.6486, and HDR tone mapping is still maxing the CPU causing may pauses. Turn it off, and HW transcode works fine.

1 Like
5

Can confirm. Updated my Plex server to 1.30.0.6486. Still having the same issue. Once HDR tone mapping is enabled, it will solely use the CPU for transcoding.

1 Like
6

Confirmed again on Version 1.30.2.6563. Same issue. Transcoding of 4k material is solely software based. Turn off HDR Tone Mapping, and it goes back to hw transcoding.

Beginning to think there is more to it that we’re hearing about.

7

Have a look into the following thread. Unfortunately I haven’t heard back from @ChuckPa in that thread so I’m not sure if it’s really related to drivers and driver downloading.

I was looking into it and figured out, that going back to 1.29.x seems to do something with drivers or so that will then make it work again. Even if you update to 1.30.x afterwards.

At least that’s what happened on my machine.

8

The thread you mentioned is this thread. I’ve gone back to 1.28.x where it worked and then back to 1.29.x or 1.30.x, and I get the same result. Interestingly, the jump to 1.29 was supposed to fix it, and it did. However, then a new 1.29 build was released, and it broke again. I wasn’t able to find the 1.29 build that worked anymore. The only way I’ve seen it work is to go back to 1.28, but I’m too far along at this point to go back that far.

To be clear, I’m running everything on Docker, so the drivers are all in the container. Given hw transcode works without HDR tone mapping on, and it did work with previous versions of Plex, I’m guessing there is a problem in the containers.

9

Also, my docker host is an i3 NUC running Ubuntu 22.04.1 LTS server — all latest updates are installed.

10

Respectfully,

I see repeated confirming of a problem but I don’t see any DEBUG log files which capture the failure for us to recreate and fix.

11

Sorry, I will collect those now. I’ve posted in other threads.

12

The file is too big to upload. You can access it here:

The two last showings of “Inglourious Basterds” are:

  1. HDR Off: Plays with HW transcoding
  2. HDR On: Does not use HW transcoding and buries my CPU

Respectfully, logs for this error have been posted multiple times by others as well.

13

The file wasn’t too big… something stupid with the forums.
Default rollover count of 5 fits in about 5-6 MB… never been an issue. :person_shrugging:

I see the error occur after several playback+terminate from iOS.

Here’s the actual error happening

Jan 25, 2023 15:41:38.636 [0x7fb32b3b7b38] ERROR - [Req#1952/Transcode/D05D1F40-FDAD-490B-906C-C1AB7DAC194E/5d3353b4-58d7-4257-acac-b35c1042a437] Error while processing the decoded data for stream #0:0
Jan 25, 2023 15:41:38.636 [0x7fb333acbb38] DEBUG - Completed: [127.0.0.1:45950] 200 POST /video/:/transcode/session/D05D1F40-FDAD-490B-906C-C1AB7DAC194E/5d3353b4-58d7-4257-acac-b35c1042a437/progress/log?level=0&message=Error%20while%20processing%20the%20decoded%20data%20for%20stream%20%230%3A0 (18 live) 0ms 195 bytes (pipelined: 28) (range: bytes=0-) 
Jan 25, 2023 15:41:38.661 [0x7fb333d11b38] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Transcoder' exit code for process 7731 is 1 (failure)
Jan 25, 2023 15:41:38.661 [0x7fb32f19fb38] DEBUG - Streaming Resource: Changing client to use software decoding
Jan 25, 2023 15:41:38.661 [0x7fb32f19fb38] DEBUG - TranscodeUniversalRequest: adapting profile with augmentation data: add-direct-play-profile(type=videoProfile&protocol=http&container=mkv&videoCodec=*&audioCodec=*&subtitleCodec=*)+add-direct-play-profile(type=videoProfile&protocol=hls&container=mkv&videoCodec=*&audioCodec=*&subtitleCodec=*)+add-transcode-target(type=videoProfile&context=streaming&protocol=hls&container=mkv&videoCodec=h264,hevc,png,apng,bmp,mjpeg,thp,gif,vp8,vp9,dirac,ffv1,ffvhuff,huffyuv,rawvideo,012v,ayuv,r210,v210,v210x,v308,v408,v410,y41p,yuv4,ansi,h263,mpeg1video,mpeg2video,mpeg4,vc1&audioCodec=ape,aac,aac_latm,alac,dca,vorbis,opus,pcm,pcm_alaw,pcm_mulaw,pcm_bluray,pcm_dvd,mp1,mp2,eac3,ac3,flac,mp3&subtitleCodec=vobsub&replace=true)+add-transcode-target-settings(type=videoProfile&context=streaming&protocol=hls&CopyMatroskaAttachments=true)+add-limitation(scope=videoAudioCodec&scopeName=*&type=upperBound&name=audio.channels&value=10&replace=true)+add-limitation(scope=videoCodec&scopeName=*&type=upperBound&name=video.bitDepth&value=10&replace=true)+add-limitation(scope=videoCodec&scopeName=*&type=notMatch&name=video.separateFields&value=dummy&replace=true)+add-limitation(scope=videoCodec&scopeName=*&type=upperBound&name=video.width&value=4096&replace=true)+add-limitation(scope=videoCodec&scopeName=*&type=upperBound&name=video.height&value=2160&replace=true)+add-limitation(scope=videoCodec&scopeName=*&type=upperBound&name=video.width&value=4096&onlyTranscodes=true&replace=false)+add-limitation(scope=videoCodec&scopeName=*&type=upperBound&name=video.height&value=2160&onlyTranscodes=true&replace=false)

while here it play3ed ok

Jan 25, 2023 15:41:37.982 [0x7fb32b3b7b38] DEBUG - [Req#18ee/Transcode] [FFMPEG] - Slice 0 data buffer (47 bytes) is 0x2.
Jan 25, 2023 15:41:37.982 [0x7fb32b3b7b38] DEBUG - [Req#18ee/Transcode] [FFMPEG] - Decode to surface 0x13.
Jan 25, 2023 15:41:37.983 [0x7fb32b3b7b38] DEBUG - [Req#18ee/Transcode] Codecs: 10-bit HEVC test succeeded
Jan 25, 2023 15:41:37.983 [0x7fb32b3b7b38] DEBUG - [Req#18ee/Transcode] MDE: Inglourious Basterds (2009): Audio Direct Streaming is disabled, so video's audio stream will be transcoded
Jan 25, 2023 15:41:37.983 [0x7fb32b3b7b38] DEBUG - [Req#18ee/Transcode] MDE: Cannot direct stream audio stream due to profile or setting limitations
Jan 25, 2023 15:41:37.983 [0x7fb32b3b7b38] DEBUG - [Req#18ee/Transcode] MDE: Inglourious Basterds (2009): selected media 0 / 90497
Jan 25, 2023 15:41:37.984 [0x7fb32b3b7b38] DEBUG - [Req#18ee/Transcode] Streaming Resource: Reached Decision id=86395 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=90497 part=(id=127013 decision=transcode container=mkv protocol=hls streams=(Video=(id=128031 decision=transcode bitrate=9006 encoder=h264_vaapi width=1920 height=1080) Audio=(id=128032 decision=transcode bitrate=127 encoder=libopus channels=2 rate=48000))))
Jan 25, 2023 15:41:37.985 [0x7fb333acbb38] DEBUG - Completed: [192.168.1.187:65528] 200 GET /video/:/transcode/universal/decision?advancedSubtitles=text&audioBoost=100&autoAdjustQuality=0&directPlay=0&directStream=1&directStreamAudio=1&location=lan&mediaBufferSize=40000&partIndex=0&path=%2Flibrary%2Fmetadata%2F86395&protocol=hls&subtitleSize=100&subtitles=auto&videoBitrate=10000&videoResolution=4096x2160 (15 live) TLS GZIP 27ms 5760 bytes (pipelined: 16)
Jan 25, 2023 15:41:38.001 [0x7fb32d48eb38] DEBUG - Request: [192.168.1.187:65526 (Subnet)] GET /hubs/metadata/86395/related?includeAugmentations=1&includeExternalMetadata=1&includeMeta=1 (15 live) #18f9 TLS GZIP Signed-in Token (gobigdave) (iPad)
Jan 25, 2023 15:41:38.003 [0x7fb32b1b4b38] DEBUG - Request: [192.168.1.187:65528 (Subnet)] GET /:/timeline?bufferedTime=24&col=9&context=source%3Acontent.library&duration=26000&key=%2Flibrary%2Fmetadata%2F86395&location=lan&playQueueItemID=74378&playbackTime=10&ratingKey=86395&row=9&state=buffering&time=0 (15 live) #18fd TLS GZIP Signed-in Token (gobigdave) (iPad)
Jan 25, 2023 15:41:38.004 [0x7fb32b1b4b38] DEBUG - [Req#18fd] Client [778A4500-2235-4B04-A3EE-3B736E3D62C4] reporting timeline state buffering, progress of 0/26000ms for guid=, playbackTime=10ms ratingKey=86395 url=, key=/library/metadata/86395, containerKey=, metadataId=86395, source=
Jan 25, 2023 15:41:38.004 [0x7fb32b1b4b38] DEBUG - [Req#18fd] [Now] User is gobigdave (ID: 1)
Jan 25, 2023 15:41:38.004 [0x7fb32b1b4b38] DEBUG - [Req#18fd] [Now] Device is iOS (iPad).

where the previous run exited normally (exit code for process 7697 is 0)

Jan 25, 2023 15:41:35.271 [0x7fb3338c8b38] DEBUG - Completed: [127.0.0.1:45934] 200 POST /video/:/transcode/session/0EE8C813-DEE4-4B58-A956-EA278CA12F72/89de3902-0524-445b-afb7-38c7cdab1ddf/manifest (18 live) 0ms 166 bytes
Jan 25, 2023 15:41:35.275 [0x7fb32ec47b38] DEBUG - Request: [127.0.0.1:45944 (Loopback)] POST /video/:/transcode/session/0EE8C813-DEE4-4B58-A956-EA278CA12F72/89de3902-0524-445b-afb7-38c7cdab1ddf/manifest (18 live) #18c1 Signed-in
Jan 25, 2023 15:41:35.275 [0x7fb32ec47b38] DEBUG - [Req#18c1/Transcode/0EE8C813-DEE4-4B58-A956-EA278CA12F72/89de3902-0524-445b-afb7-38c7cdab1ddf] Transcoder segment range: 0 - 25 (25)
Jan 25, 2023 15:41:35.276 [0x7fb32d48eb38] DEBUG - Request: [127.0.0.1:45488 (Loopback)] PUT /video/:/transcode/session/0EE8C813-DEE4-4B58-A956-EA278CA12F72/89de3902-0524-445b-afb7-38c7cdab1ddf/progress?progress=96.0&size=-22&remaining=0&vdec_packets=603&vdec_hw_ok=603&speed=5.2&vdec_hw_status=1 (18 live) #18b3 Signed-in Token (gobigdave) (range: bytes=0-) 
Jan 25, 2023 15:41:35.276 [0x7fb3338c8b38] DEBUG - Completed: [127.0.0.1:45944] 200 POST /video/:/transcode/session/0EE8C813-DEE4-4B58-A956-EA278CA12F72/89de3902-0524-445b-afb7-38c7cdab1ddf/manifest (18 live) 0ms 166 bytes
Jan 25, 2023 15:41:35.276 [0x7fb333acbb38] DEBUG - Completed: [127.0.0.1:45488] 206 PUT /video/:/transcode/session/0EE8C813-DEE4-4B58-A956-EA278CA12F72/89de3902-0524-445b-afb7-38c7cdab1ddf/progress?progress=96.0&size=-22&remaining=0&vdec_packets=603&vdec_hw_ok=603&speed=5.2&vdec_hw_status=1 (17 live) 0ms 355 bytes (pipelined: 19) (range: bytes=0-) 
Jan 25, 2023 15:41:35.298 [0x7fb333d11b38] DEBUG - Jobs: '/usr/lib/plexmediaserver/Plex Transcoder' exit code for process 7697 is 0 (success)
Jan 25, 2023 15:41:35.302 [0x7fb32e031b38] DEBUG - [Req#18b8/Transcode/0EE8C813-DEE4-4B58-A956-EA278CA12F72] Returning segment 24 from session
Jan 25, 2023 15:41:35.302 [0x7fb32e031b38] DEBUG - Content-Length of /transcode/Transcode/Sessions/plex-transcode-0EE8C813-DEE4-4B58-A956-EA278CA12F72-89de3902-0524-445b-afb7-38c7cdab1ddf/media-00024.ts is 817511 (of total: 817511).
Jan 25, 2023 15:41:35.310 [0x7fb333acbb38] DEBUG - Completed: [192.168.1.187:52487] 206 GET /video/:/transcode/universal/session/0EE8C813-DEE4-4B58-A956-EA278CA12F72/base/00024.ts (16 live) TLS 107ms 817511 bytes (pipelined: 13) (range: bytes=0-) 
Jan 25, 2023 15:41:35.310 [0x7fb333acbb38] DEBUG - Removed transcode data consumer, active count 1 => 0
Jan 25, 2023 15:41:35.322 [0x7fb330dd9b38] DEBUG - Request: [192.168.1.187:65526 (Subnet)] GET /transcode/sessions (16 live) #185b TLS GZIP Signed-in Token (gobigdave) (iPad)
Jan 25, 2023 15:41:35.322 [0x7fb32b3b7b38] DEBUG - Request: [192.168.1.187:65528 (Subnet)] GET /:/timeline?bufferedTime=3&context=&duration=25150&key=%2Flibrary%2Fmetadata%2F98547&location=lan&playQueueItemID=74379&playbackTime=0&ratingKey=98547&state=playing&time=0&timeToFirstFrame=4 (16 live) #1860 TLS GZIP Signed-in Token (gobigdave) (iPad)

What changed to cause the different playback conditions?

14

Not sure about the log size. I just know it failed when I tried to upload it.

Here’s what I did:

  1. I first turned on verbose logging
  2. Turned on HDR
  3. Tried to play the movie. This one just hung and never got started.
  4. Turned off HDR
  5. Movie played successfully. This is probably the previous play you mentioned.
  6. Turned off verbose logging (left debug logging on)
  7. Played the movie successfully with HDR off
  8. Turn HDR on
  9. Movie did not use hw transcoding

I do have a Dolby ATMOS clip that plays before each attempt. Don’t know if that matters.

15

Wish the log listed what the error actually was vs. “failed”. :slight_smile:

Also, my transcoding directory is a RAM disk now. Same error happened when it used to be an SSD, but want to be sure you have the whole picture.

16

strip the issue back to the basics for testing.

Let’s find what works.

17

You’re right, my bad. Here’s the correct link: Hardware transcoding not working for 4k HDR content using 12th Gen Intel via Quick Sync

18

Removing the pre-roll video did not change the behavior, and the logs have the same issue. I can watch it happen in the dashboard. “Now Playing” shows hw transcoding for a few seconds, and then it switches to sw and my CPU jumps for 10-15% to 100%.

1 Like
19

Confirmed that 1.31.1.6733 still has same behavior and log entries.

Play starts off hw, but then drops back to sw after a few seconds.

20

It’s been several months now since I setup hw transcoding in TrueNAS Core (13.0-U4) with my Intel i7-7700 using QuickSync and this is still broken. Having purchasing a lifetime PlexPass purely for this reason, it’s incredibly frustrating this is still not working.

Is this bug acknowledged by Plex staff? Is this something that is being worked on?
It’s great that Plex is still being actively developed with frequent new releases, however very tiring reading the changelog only to find this bug not recieving any love.

Thanks for your time and I look forward to hearing from the Plex staff on this.

Cheers.