PGS and Vobsub burn-in fails with hw transcode, FreeBSD 12.1

Server Version#: 1.19.4.2935 on FreeBSD 12.1
Player Version#: Plex Web Version 4.37.2

Kaby Lake CPU (E3-1225v6) with hw transcode enabled.

Movies with PGS or vobsub subtitles will fail to play. Player will just “sit there”, logs from starting, waiting for a bit and then cancelling below.

Switching hw transcode off resolves the issue.

I’m assuming the answer is “Intel needs to fix iHD”, and, it’s always good to verify.

Software transcode works and is adequate for what I’m doing.

Transcoder Statistics Log:

<Variants>
<Variant id="2da9fa81-02f0-45c1-97c1-b812c741aedc" targetBitrate="26948" context="streaming" sourceVideoCodec="h264" sourceAudioCodec="dca" videoDecision="transcode" audioDecision="transcode" subtitleDecision="burn" protocol="dash" container="mp4" videoCodec="h264" audioCodec="aac" audioChannels="2" transcodeHwRequested="1" transcodeHwDecoding="vaapi" transcodeHwEncoding="vaapi" transcodeHwDecodingTitle="Intel (VA API)" transcodeHwEncodingTitle="Intel (VA API)" transcodeHwFullPipeline="0">
<Media audioProfile="ma" id="7362" videoProfile="high" audioChannels="2" audioCodec="aac" bitrate="25664" container="mp4" duration="7333331" height="1080" optimizedForStreaming="1" protocol="dash" videoCodec="h264" videoFrameRate="24p" videoResolution="1080p" width="1920" selected="1">
<Part audioProfile="ma" deepAnalysisVersion="4" id="7547" indexes="sd" requiredBandwidths="33909,32325,30288,28041,27146,26525,23498,21773" videoProfile="high" bitrate="25664" container="mp4" duration="7333331" height="1080" optimizedForStreaming="1" protocol="dash" width="1920" decision="transcode" selected="1">
<Stream bitrate="25408" chromaLocation="left" codec="h264" colorPrimaries="bt709" colorTrc="bt709" displayTitle="1080p (H.264)" frameRate="23.975999999999999" height="1080" id="10792" language="English" languageCode="eng" requiredBandwidths="31114,29408,27432,25213,24420,23786,20772,19253" streamType="1" width="1920" decision="transcode" location="segments-video" />
<Stream bitrate="256" bitrateMode="cbr" channels="2" codec="aac" default="1" displayTitle="&#54620;&#44397;&#50612; (DTS-HD MA 5.1)" id="10793" language="&#54620;&#44397;&#50612;" languageCode="kor" requiredBandwidths="2655,2565,2446,2446,2446,2446,2446,2446" selected="1" streamType="2" decision="transcode" location="segments-audio" />
<Stream burn="1" default="1" displayTitle="English (PGS)" id="10794" language="English" languageCode="eng" requiredBandwidths="30,30,30,30,30,30,30,30" selected="1" streamType="3" decision="burn" location="segments-video" />
</Part>
</Media>
</Variant>
</Variants>
<SegmentList>
<Segment duration="0" startOffset="-1" endOffset="-1">
<Timelines>
<Download startTime="116" fileType="audio" variant="2da9fa81-02f0-45c1-97c1-b812c741aedc" />
<Download startTime="117" fileType="video" variant="2da9fa81-02f0-45c1-97c1-b812c741aedc" />
<Download startTime="127749" fileType="video" variant="2da9fa81-02f0-45c1-97c1-b812c741aedc" />
<Download startTime="128143" fileType="audio" variant="2da9fa81-02f0-45c1-97c1-b812c741aedc" />
</Timelines>
</Segment>
</SegmentList>
<PlaybackReports>
<Playback startTime="157412" endTime="158437" state="paused" progress="3300000" />
<Playback startTime="158437" endTime="162728" state="playing" progress="3300000" />
<Playback startTime="162728" state="stopped" progress="3300000" />
</PlaybackReports>
<StateReports />
<StateReports />
</SessionReport>

Plex Media Server log:

Jul 10, 2020 13:57:13.940 [0x80c2c8f00] WARN - [FFMPEG] - No quality level set; using default (20).
Jul 10, 2020 13:58:04.077 [0x80c20e400] WARN - Deleted file "/tmp/logs.zip1308326b-abd5-4c3b-a5b3-69212a549cfa" after connection reset
Jul 10, 2020 13:59:20.962 [0x81724d700] WARN - Timed out waiting for segment.
Jul 10, 2020 13:59:21.070 [0x81658d600] WARN - Timed out waiting for segment.
Jul 10, 2020 13:59:56.813 [0x817226200] ERROR - Unknown metadata type: folder
Jul 10, 2020 13:59:56.878 [0x816422f00] WARN - Transcode runner appears to have died.
Jul 10, 2020 13:59:56.878 [0x81658b800] WARN - Transcode runner appears to have died.
Jul 10, 2020 13:59:59.222 [0x816425700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Jul 10, 2020 13:59:59.242 [0x816425700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Jul 10, 2020 13:59:59.251 [0x816425700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Jul 10, 2020 14:00:02.243 [0x816ffa400] ERROR - Unknown metadata type: folder
Jul 10, 2020 14:00:29.378 [0x81724be00] ERROR - Unknown metadata type: folder

Odd it should fallback to software, HWT with burned image subs is not supported, if the client can’t play PGS we will need to fallback to software, it seems the issue here is that its not handling the fallback properly.

EDIT: actually I stand corrected we do support HTW in this case (not sure if it was always the case, but we do now for, I just tested with my BSD box and Web Player), HW encoding/decoding will work, but it still needs some CPU work. In any case HWT should indeed be working in such a scenario, it just means you should still see an impact in CPU, because it will still need to burn PGS subs.

Can you post the full zip with logs? This is working on my BSD setup, does it happen with combination of codecs as long as PGS/VOBSUB is involved?

Thank you for being willing to take a look! I think the full logs have my token in them, I’ll PM you a link to a cloud share.

Since this is working in your environment, maybe we can figure out what’s different.

And yes, the only common thread is VOBSUB or PGS subtitles. Tested with MPEG2VIDEO and H.264 codecs, 480i, 480p and 1080p resolutions.

For the debug, these are the videos I tested and the rough start and stop times.

Test to show hw transcode works at all

VC1 Transcode test, start ~12:03PM EDT

Each video ~5 minutes wait, then killed when it didn’t start

Das Boot, start ~12:08PM EDT, stop ~12:13PM EDT:
480i (MPEG2VIDEO), VOBSUB

Spirited Away, start ~12:13PM EDT, stop ~12:21PM EDT:
480p (MPEG2VIDEO), VOBSUB

House of Flying Daggers, start ~12:21PM EDT, stop ~12:28PM EDT:
1080p (MPEG2VIDEO), PGS

War of the Arrows OpenSubtitles, start ~12:28PM EDT: Plays fine
Changed to PGS around 12:29PM EDT, error: “Conversion failed. The transcoder failed to start up”
1080p (H.264), PGS

One more: Once I have the failure reproduced, I am also unable to transcode videos without subtitles. Which means it’s possible that one of those codec combinations is “deadlier” than the others.

Once Plex gets into this state, only a restart of the jail gets it back out again.

One way to reproduce: War of the arrows with SRT (opensub), switch over to PGS, get the error (see earlier message) - at this point hardware transcoding any video will fail.

Edit: There’s a very stubborn transcode process that won’t even respond to kill -9. Wow.

root@pms:~ # kill -9 11806
root@pms:~ # ps -ax
  PID TT  STAT    TIME COMMAND
 4228  -  SsJ  0:00.02 /usr/sbin/syslogd -c -ss
 4286  -  TsJ  1:10.98 /usr/local/share/plexmediaserver/Plex_Media_Server (Plex Media Server)
 4293  -  IsJ  0:00.03 /usr/sbin/cron -J 15 -s
 4773  -  INJ  0:14.80 Plex Plug-in [com.plexapp.system] /usr/local/share/plexmediaserver/Resources/Plug-ins-79e214ead/
 5004  -  IJ   0:04.01 /usr/local/share/plexmediaserver/Plex DLNA Server
 5005  -  IJ   0:00.32 /usr/local/share/plexmediaserver/Plex Tuner Service /usr/local/share/plexmediaserver/Resources/T
11806  -  DJ   0:00.14 /usr/local/share/plexmediaserver/Plex Transcoder -codec:0 h264 -hwaccel:0 vaapi -hwaccel_fallbac

Plex Media Server is stuck in STOP and CONT or KILL or -9 won’t get it out of that; same for transcoder. Will reboot.

Here’s output of top -P.

 PID USERNAME    THR PRI NICE   SIZE    RES STATE    C   TIME    WCPU COMMAND
 4773 plex         13  52   15   121M    69M piperd   0   0:32   0.04% Plex Script Host
42464 root          1  20    0    13M  3544K CPU0     0   0:00   0.01% top
 5004 plex         13  26    0   144M    75M usem     1   0:10   0.00% Plex DLNA Server
 5005 plex         11  20    0    40M    21M usem     2   0:01   0.00% Plex Tuner Service
 4286 plex          6  20    0   301M   122M STOP     0   1:11   0.00% Plex Media Server
11806 plex         14  20    0   305M   155M i915fl   2   0:00   0.00% Plex Transcoder

More testing and output of top and ps before, during and after attempted video playback.

Before starting fatal transcode

  PID USERNAME    THR PRI NICE   SIZE    RES STATE    C   TIME    WCPU COMMAND
 8387 plex         24  52    0   269M   110M uwait    2   0:01   0.25% Plex Media Server
 8434 plex         15  52   15   111M    59M piperd   3   0:02   0.18% Plex Script Host
 8441 plex         10  52    0    86M    50M piperd   0   0:01   0.03% Plex Script Host
 8439 plex         14  52    0   128M    67M usem     1   0:00   0.03% Plex DLNA Server
 8574 root          1  20    0    13M  3560K CPU2     2   0:00   0.01% top
 8440 plex         11  52    0    40M    21M usem     0   0:00   0.00% Plex Tuner Service

Start War of Arrows 6:06, with PGS and hardware transcode

 PID USERNAME    THR PRI NICE   SIZE    RES STATE    C   TIME    WCPU COMMAND
 8387 plex         27  52    0   397M   207M uwait    2   0:05   0.35% Plex Media Server
 8434 plex         14  52   15   129M    79M piperd   3   0:02   0.07% Plex Script Host
 8441 plex         10  52    0    86M    50M piperd   0   0:01   0.01% Plex Script Host
 8574 root          1  20    0    13M  3560K CPU1     1   0:00   0.01% top
 8439 plex         13  52    0   128M    67M usem     1   0:00   0.00% Plex DLNA Server
 8440 plex         11  52    0    40M    21M usem     0   0:00   0.00% Plex Tuner Service
 8614 plex         14  26    0   305M   152M i915fl   0   0:00   0.00% Plex Transcoder
 
 
 root@pms:~ # ps -axww
 PID TT  STAT    TIME COMMAND
8329  -  IsJ  0:00.00 /usr/sbin/syslogd -c -ss
8387  -  IsJ  0:05.22 /usr/local/share/plexmediaserver/Plex_Media_Server (Plex Media Server)
8394  -  SsJ  0:00.00 /usr/sbin/cron -J 15 -s
8434  -  INJ  0:02.09 Plex Plug-in [com.plexapp.system] /usr/local/share/plexmediaserver/Resources/Plug-ins-79e214ead/Framework.bundle/Contents/Resources/Versions/2/Python/bootstrap.py --server-version 1.19.4.2935-79e214ead /usr/local/share/plexmediaserver/Resources/Plug-ins-79e214ead/System.bundle (Plex Script Host)
8439  -  IJ   0:00.32 /usr/local/share/plexmediaserver/Plex DLNA Server
8440  -  IJ   0:00.02 /usr/local/share/plexmediaserver/Plex Tuner Service /usr/local/share/plexmediaserver/Resources/Tuner/Private /usr/local/share/plexmediaserver/Resources/Tuner/Shared 1.19.4.2935-79e214ead 32600 /waitmutex
8441  -  IJ   0:01.24 Plex Plug-in [com.plexapp.agents.imdb] /usr/local/share/plexmediaserver/Resources/Plug-ins-79e214ead/Framework.bundle/Contents/Resources/Versions/2/Python/bootstrap.py --server-version 1.19.4.2935-79e214ead /usr/local/share/plexmediaserver/Resources/Plug-ins-79e214ead/PlexMovie.bundle (Plex Script Host)
8614  -  DJ   0:00.15 /usr/local/share/plexmediaserver/Plex Transcoder -codec:0 h264 -hwaccel:0 vaapi -hwaccel_fallback_threshold:0 10 -codec:1 dca -analyzeduration 20000000 -probesize 20000000 -i /media/Movies/WAR OF THE ARROWS/War of the Arrows.mkv -filter_complex [0:2]scale=1920:1080[0];[0:0][0]overlay[1];[1]scale=w=1920:h=1080[2];[2]format=pix_fmts=nv12[3];[3]hwupload[4] -filter_complex [0:1] aresample=async=1:ocl='stereo':osr=48000[5] -map [4] -metadata:s:0 language=eng -codec:0 h264_vaapi -b:0 19958k -maxrate:0 26611k -bufsize:0 53222k -r:0 23.975999999999999 -force_key_frames:0 expr:gte(t,0+n_forced*1) -map [5] -metadata:s:1 language=kor -codec:1 aac -b:1 256k -f dash -seg_duration 1 -init_seg_name init-stream$RepresentationID$.m4s -media_seg_name chunk-stream$RepresentationID$-$Number%05d$.m4s -window_size 5 -delete_removed false -skip_to_segment 1 -time_delta 0.0625 -manifest_name http://127.0.0.1:32400/video/:/transcode/session/zkiggj5og0b5x1g50436zhui/b747a14d-71e8-4987-9963-b77a82ed6f21/manifest?X-Plex-Http-Pipeline=infinite -avoid_negative_ts disabled -map_metadata -1 -map_chapters -1 dash -start_at_zero -copyts -vsync cfr -y -init_hw_device vaapi=vaapi:,driver=iHD -hwaccel_device vaapi -filter_hw_device vaapi -nostats -loglevel quiet -loglevel_plex error -progressurl http://127.0.0.1:32400/video/:/transcode/session/zkiggj5og0b5x1g50436zhui/b747a14d-71e8-4987-9963-b77a82ed6f21/progress

Abort around 6:09, note Plex Transcoder doesn’t quit

  PID USERNAME    THR PRI NICE   SIZE    RES STATE    C   TIME    WCPU COMMAND
 8434 plex         14  52   15   129M    79M piperd   3   0:02   0.06% Plex Script Host
 8387 plex         20  52    0   399M   210M uwait    2   0:06   0.06% Plex Media Server
 8439 plex         13  52    0   128M    67M usem     1   0:00   0.02% Plex DLNA Server
 8441 plex         10  52    0    86M    50M piperd   0   0:01   0.01% Plex Script Host
 8678 root          1  20    0    13M  3544K CPU3     3   0:00   0.01% top
 8440 plex         11  52    0    40M    21M usem     0   0:00   0.00% Plex Tuner Service
 8614 plex         14  20    0   305M   152M i915fl   0   0:00   0.00% Plex Transcoder
 
 root@pms:~ # ps -axww
 PID TT  STAT    TIME COMMAND
8329  -  SsJ  0:00.00 /usr/sbin/syslogd -c -ss
8387  -  IsJ  0:06.47 /usr/local/share/plexmediaserver/Plex_Media_Server (Plex Media Server)
8394  -  IsJ  0:00.00 /usr/sbin/cron -J 15 -s
8434  -  INJ  0:02.20 Plex Plug-in [com.plexapp.system] /usr/local/share/plexmediaserver/Resources/Plug-ins-79e214ead/Framework.bundle/Contents/Resources/Versions/2/Python/bootstrap.py --server-version 1.19.4.2935-79e214ead /usr/local/share/plexmediaserver/Resources/Plug-ins-79e214ead/System.bundle (Plex Script Host)
8439  -  IJ   0:00.34 /usr/local/share/plexmediaserver/Plex DLNA Server
8440  -  IJ   0:00.03 /usr/local/share/plexmediaserver/Plex Tuner Service /usr/local/share/plexmediaserver/Resources/Tuner/Private /usr/local/share/plexmediaserver/Resources/Tuner/Shared 1.19.4.2935-79e214ead 32600 /waitmutex
8441  -  IJ   0:01.25 Plex Plug-in [com.plexapp.agents.imdb] /usr/local/share/plexmediaserver/Resources/Plug-ins-79e214ead/Framework.bundle/Contents/Resources/Versions/2/Python/bootstrap.py --server-version 1.19.4.2935-79e214ead /usr/local/share/plexmediaserver/Resources/Plug-ins-79e214ead/PlexMovie.bundle (Plex Script Host)
8614  -  DJ   0:00.15 /usr/local/share/plexmediaserver/Plex Transcoder -codec:0 h264 -hwaccel:0 vaapi -hwaccel_fallback_threshold:0 10 -codec:1 dca -analyzeduration 20000000 -probesize 20000000 -i /media/Movies/WAR OF THE ARROWS/War of the Arrows.mkv -filter_complex [0:2]scale=1920:1080[0];[0:0][0]overlay[1];[1]scale=w=1920:h=1080[2];[2]format=pix_fmts=nv12[3];[3]hwupload[4] -filter_complex [0:1] aresample=async=1:ocl='stereo':osr=48000[5] -map [4] -metadata:s:0 language=eng -codec:0 h264_vaapi -b:0 19958k -maxrate:0 26611k -bufsize:0 53222k -r:0 23.975999999999999 -force_key_frames:0 expr:gte(t,0+n_forced*1) -map [5] -metadata:s:1 language=kor -codec:1 aac -b:1 256k -f dash -seg_duration 1 -init_seg_name init-stream$RepresentationID$.m4s -media_seg_name chunk-stream$RepresentationID$-$Number%05d$.m4s -window_size 5 -delete_removed false -skip_to_segment 1 -time_delta 0.0625 -manifest_name http://127.0.0.1:32400/video/:/transcode/session/zkiggj5og0b5x1g50436zhui/b747a14d-71e8-4987-9963-b77a82ed6f21/manifest?X-Plex-Http-Pipeline=infinite -avoid_negative_ts disabled -map_metadata -1 -map_chapters -1 dash -start_at_zero -copyts -vsync cfr -y -init_hw_device vaapi=vaapi:,driver=iHD -hwaccel_device vaapi -filter_hw_device vaapi -nostats -loglevel quiet -loglevel_plex error -progressurl http://127.0.0.1:32400/video/:/transcode/session/zkiggj5og0b5x1g50436zhui/b747a14d-71e8-4987-9963-b77a82ed6f21/progress

I tried this on FreeBSD 11.3 instead of 12.1 - and the issue is gone, I can use hardware transcoding with PGS. I’ll get you a debug for that, as well.

This suggests the issue might be with 12.1, or my install of 12.1, or the way Plex interacts with 12.1.

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