Server Version#: 1.17.0.1709
Player Version#:
I recently replaced my server to take advantage of HW transcoding. New system is AMD Ryzen with an nVidia 1660. Installed Plex, rescanned media library, and it seems to work fine for all my media files except the older AVI-based files. When I attempt play them, I get the rotating circle and eventually it just fails. If I disable HW transcoding, it plays back just fine (this is both via AppleTV and Chrome browser).
The only errors I can glean from the log files are there:
Oct 02, 2019 06:46:21.896 [0x7f1a16ffd700] ERROR - XML: namespace
Oct 02, 2019 06:46:21.896 [0x7f1a16ffd700] ERROR - XML: error :
Oct 02, 2019 06:46:21.896 [0x7f1a16ffd700] ERROR - XML: xmlns:ms: ' urn:microsoft-com:wmc-1-0' is not a valid URI
Oct 02, 2019 06:46:21.896 [0x7f1a16ffd700] ERROR - XML: xmlns:ms=" urn:microsoft-com:wmc-1-0"
Oct 02, 2019 06:46:21.896 [0x7f1a16ffd700] ERROR - XML:
and
Oct 02, 2019 06:46:44.088 [0x7f19f77fe700] ERROR - [FFMPEG] - No VA display found for device: /dev/dri/renderD128.
Oct 02, 2019 06:46:44.088 [0x7f19f77fe700] DEBUG - Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: Invalid argument
Oct 02, 2019 06:46:44.088 [0x7f19f77fe700] DEBUG - Codecs: hardware transcoding: testing API nvdec
Although I dismiss that last one, as it seems to pickup on the nvidia card just fine and there are no errors associated with that, as it finds all the libraries its looking for.
Here’s (possibly) more relevant sections of the debug log:
Oct 02, 2019 06:46:44.368 [0x7f19f77fe700] DEBUG - Scaled up video bitrate to 2383Kbps based on 1.500000x fudge factor.
Oct 02, 2019 06:46:44.368 [0x7f19f77fe700] DEBUG - MDE: Cannot direct stream audio stream due to codec mp3 when profile only allows aac
Oct 02, 2019 06:46:44.368 [0x7f19f77fe700] DEBUG - MDE: A History of Britain by Simon Schama - S1 E3 - Dynasty (1087 - 1216): selected media 0 / 12319
Oct 02, 2019 06:46:44.368 [0x7f19f77fe700] DEBUG - Streaming Resource: Adding session 0x7f19dc568f00:ij0kx3jwirivrphrej22x77v which is using transcoder slot. Used slots is now 1
Oct 02, 2019 06:46:44.368 [0x7f19f77fe700] DEBUG - Streaming Resource: Added session 0x7f19dc568f00:ij0kx3jwirivrphrej22x77v
Oct 02, 2019 06:46:44.368 [0x7f19f77fe700] DEBUG - Streaming Resource: Reached Decision id=4865 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=12319 part=(id=12319 decision=transcode container=mp4 protocol=dash streams=(Video=(id=54492 decision=transcode bitrate=2383 encoder=h264_nvenc width=624 height=352) Audio=(id
=54493 decision=transcode bitrate=256 encoder=aac channels=2 rate=48000))))
Oct 02, 2019 06:46:44.369 [0x7f1a4b7fe700] DEBUG - Completed: [192.168.0.1:2770] 200 GET /video/:/transcode/universal/decision?hasMDE=1&path=%2Flibrary%2Fmetadata%2F4865&mediaIndex=0&partIndex=0&protocol=dash&fastSeek=1&directPlay=0&directStream=1&subtitleSize=100&audioBoost=100&location=wan&addDebugOverlay=0&autoAdjustQuality=1&directStreamAudio=1&mediaBufferSize=102400&session=j63lmfev0qtsoi2r6cetp9ue&subtitles=burn&Accept-Language=en (12 live) TLS GZIP 437ms 1606 bytes
(pipelined: 11)
Oct 02, 2019 06:46:44.405 [0x7f1a2effd700] DEBUG - [Notify] Now watching "/data/share/media/video/movies/Robin Hood- Men in Tights (1993)/Plex Versions"
Oct 02, 2019 06:46:44.405 [0x7f1a2effd700] DEBUG - [Notify] Now watching "/data/share/media/video/movies/Dark Knight, The (2008)"
Oct 02, 2019 06:46:44.437 [0x7f1a4bfff700] DEBUG - Auth: authenticated user 1 as belisarivs
Oct 02, 2019 06:46:44.437 [0x7f1a157fa700] DEBUG - Request: [192.168.0.1:2770 (Subnet)] GET /video/:/transcode/universal/start.mpd?hasMDE=1&path=%2Flibrary%2Fmetadata%2F4865&mediaIndex=0&partIndex=0&protocol=dash&fastSeek=1&directPlay=0&directStr[Plex Media Server Logs_2019-10-02_06-43-44.zip|attachment](upload://eD8uznk4SJZCz7P3oXeo2sDkxqh.zip) (1.3 MB) eam=1&subtitleSize=100&audioBoost=100&location=wan&addDebugOverlay=0&autoAdjustQuality=1&directStreamAudio=1&mediaBufferSize=102400&session=j63lmfev0qtsoi2r6cetp9ue&subtitles=burn&Accept-Language=en (12 live) TLS GZIP Signed-in Tok
en (belisarivs)
Oct 02, 2019 06:46:44.438 [0x7f1a157fa700] DEBUG - Found session GUID of j63lmfev0qtsoi2r6cetp9ue in session start.
Oct 02, 2019 06:46:44.438 [0x7f1a157fa700] DEBUG - TranscodeUniversalRequest: using augmented profile Web
Oct 02, 2019 06:46:44.439 [0x7f1a157fa700] DEBUG - Downloading document http://127.0.0.1:32400/library/metadata/4865?checkFiles=1&includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=ij0kx3jwirivrphrej22x77v
Oct 02, 2019 06:46:44.439 [0x7f1a157fa700] DEBUG - Auth: authenticated user 1 as belisarivs
Oct 02, 2019 06:46:44.443 [0x7f1a157fa700] DEBUG - We're going to try to auto-select an audio stream for account 1.
Oct 02, 2019 06:46:44.444 [0x7f1a157fa700] DEBUG - Selecting best audio stream for part ID 12319 (autoselect: 1 language: en)
Oct 02, 2019 06:46:44.444 [0x7f1a157fa700] DEBUG - We're going to try to auto-select a subtitle.
Oct 02, 2019 06:46:44.444 [0x7f1a157fa700] DEBUG - Audio Stream: 54493, Subtitle Stream: -1
Oct 02, 2019 06:46:44.444 [0x7f1a157fa700] DEBUG - Found session GUID of j63lmfev0qtsoi2r6cetp9ue in session start.
Oct 02, 2019 06:46:44.444 [0x7f1a157fa700] DEBUG - Cleaning directory for session j63lmfev0qtsoi2r6cetp9ue ()
Oct 02, 2019 06:46:44.445 [0x7f1a157fa700] DEBUG - Starting a transcode session j63lmfev0qtsoi2r6cetp9ue at offset -1.0 (state=3)
Oct 02, 2019 06:46:44.445 [0x7f1a157fa700] DEBUG - TPU: hardware transcoding: using hardware decode accelerator nvdec
Oct 02, 2019 06:46:44.446 [0x7f1a157fa700] DEBUG - [Universal] Using local file path instead of URL: /data/share/media/video/tv/A History of Britain/Season 01/History of Britain by Simon Schama, A.S01E03.Dynasty 1087 1216.{SDTV}[Sonarr].avi
Oct 02, 2019 06:46:44.446 [0x7f1a157fa700] DEBUG - TPU: hardware transcoding: zero-copy support present
Oct 02, 2019 06:46:44.446 [0x7f1a157fa700] DEBUG - TPU: hardware transcoding: using zero-copy transcoding
Oct 02, 2019 06:46:44.446 [0x7f1a157fa700] DEBUG - TPU: hardware transcoding: final decoder: nvdec, final encoder: nvenc
Oct 02, 2019 06:46:44.446 [0x7f1a157fa700] DEBUG - Job running: EAE_ROOT='/tmp/pms-12e3b29a-bd6e-4a25-9ae9-953c8a7e7c56/EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/ba1b905-2538-linux-x86_64/' XDG_CACHE_HOME='/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache' XDG_DATA_HOME='/usr/lib/plexmediaserver/Resources' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' '/usr/lib/plexmediaserver/P
lex Transcoder' '-codec:0' 'mpeg4' '-hwaccel:0' 'nvdec' '-hwaccel_fallback_threshold:0' '10' '-hwaccel_output_format:0' 'cuda' '-codec:#0x01' 'mp3' '-analyzeduration' '20000000' '-probesize' '20000000' '-i' '/data/share/media/video/tv/A History of Britain/Season 01/History of Britain by Simon Schama, A.S01E03.Dynasty 1087 1216.{SDTV}[Sonarr].avi' '-filter_complex' '[0:0]hwupload[0];[0]scale_cuda=w=624:h=352:format=nv12[1]' '-filter_complex' '[0:#0x01] aresample=async=1:ocl
='\''stereo'\'':osr=48000[2]' '-map' '[1]' '-codec:0' 'h264_nvenc' '-b:0' '1787k' '-maxrate:0' '2383k' '-bufsize:0' '4766k' '-forced-idr:0' '1' '-r:0' '25' '-force_key_frames:0' 'expr:gte(t,0+n_forced*3)' '-map' '[2]' '-codec:1' 'aac' '-b:1' '256k' '-f' 'dash' '-seg_duration' '3' '-init_seg_name' 'init-stream$RepresentationID$.m4s' '-media_seg_name' 'chunk-stream$RepresentationID$-$Number%05d$.m4s' '-skip_to_segment' '1' '-time_delta' '0.0625' '-manifest_name' 'http://127.
0.0.1:32400/video/:/transcode/session/j63lmfev0qtsoi2r6cetp9ue/ca303d25-113c-40ab-998b-a58aa2148959/manifest' '-avoid_negative_ts' 'disabled' '-map_metadata' '-1' '-map_chapters' '-1' 'dash' '-start_at_zero' '-copyts' '-vsync' 'cfr' '-y' '-init_hw_device' 'cuda=cuda:/dev/dri/renderD128' '-hwaccel_device' 'cuda' '-filter_hw_device' 'cuda' '-nostats' '-loglevel' 'quiet' '-loglevel_plex' 'error' '-progressurl' 'http://127.0.0.1:32400/video/:/transcode/session/j63lmfev0qtsoi2r
6cetp9ue/ca303d25-113c-40ab-998b-a58aa2148959/progress'
Oct 02, 2019 06:46:44.447 [0x7f1a157fa700] DEBUG - Jobs: Starting child process with pid 16045
Oct 02, 2019 06:46:44.451 [0x7f19f7fff700] DEBUG - Request: [127.0.0.1:36392 (Loopback)] PUT /video/:/transcode/session/j63lmfev0qtsoi2r6cetp9ue/ca303d25-113c-40ab-998b-a58aa2148959/progress?status=startup (13 live) Signed-in Token (belisarivs) (range: bytes=0-)
Oct 02, 2019 06:46:44.452 [0x7f1a4bfff700] DEBUG - Completed: [127.0.0.1:36392] 204 PUT /video/:/transcode/session/j63lmfev0qtsoi2r6cetp9ue/ca303d25-113c-40ab-998b-a58aa2148959/progress?status=startup (13 live) 0ms 203 bytes (pipelined: 1) (range: bytes=0-)
The file in question I’m trying to playback is /data/share/media/video/tv/A History of Britain/Season 01/History of Britain by Simon Schama, A.S01E03.Dynasty 1087 1216.{SDTV}[Sonarr].avi
Here is the Media Info XML for it:
<MediaContainer size="1" allowSync="1" identifier="com.plexapp.plugins.library" librarySectionID="2" librarySectionTitle="TV Shows" librarySectionUUID="a59a5c8c-6f17-4468-b30f-0495ded7d301" mediaTagPrefix="/system/bundle/media/flags/" mediaTagVersion="1568420676">
<Video ratingKey="4865" key="/library/metadata/4865" parentRatingKey="4862" grandparentRatingKey="4861" guid="com.plexapp.agents.thetvdb://75678/1/3?lang=en" parentGuid="com.plexapp.agents.thetvdb://75678/1?lang=en" grandparentGuid="com.plexapp.agents.thetvdb://75678?lang=en" librarySectionTitle="TV Shows" librarySectionID="2" librarySectionKey="/library/sections/2" type="episode" title="Dynasty (1087 - 1216)" grandparentKey="/library/metadata/4861" parentKey="/library/metadata/4862" grandparentTitle="A History of Britain by Simon Schama" parentTitle="Season 1" summary="There is no saga more powerful than that of the warring dynasty - domineering father, beautiful, scheming mother and squabbling, murderous sons and daughters, (particularly the nieces). In the years that followed the Norman Conquest, this was the drama played out on the stage of British history." index="3" parentIndex="1" rating="7.3" lastViewedAt="1570010622" year="2000" thumb="/library/metadata/4865/thumb/1569980781" art="/library/metadata/4861/art/1569838934" parentThumb="/library/metadata/4862/thumb/1569838933" grandparentThumb="/library/metadata/4861/thumb/1569838934" grandparentArt="/library/metadata/4861/art/1569838934" duration="3410960" originallyAvailableAt="2000-10-14" addedAt="1286774784" updatedAt="1569980781">
<Media id="12319" duration="3410960" bitrate="1721" width="624" height="352" aspectRatio="1.78" audioChannels="2" audioCodec="mp3" videoCodec="mpeg4" videoResolution="sd" container="avi" videoFrameRate="PAL" videoProfile="simple">
<Part accessible="1" exists="1" id="12319" key="/library/parts/12319/1286774784/file.avi" duration="3410960" file="/data/share/media/video/tv/A History of Britain/Season 01/History of Britain by Simon Schama, A.S01E03.Dynasty 1087 1216.{SDTV}[Sonarr].avi" size="733657308" container="avi" indexes="sd" videoProfile="simple">
<Stream id="54492" streamType="1" codec="mpeg4" index="0" bitrate="1589" bitDepth="8" chromaLocation="left" chromaSubsampling="4:2:0" frameRate="25.000" height="352" level="3" profile="simple" refFrames="1" width="624" displayTitle="SD (MPEG4)"/>
<Stream id="54493" streamType="2" selected="1" codec="mp3" index="1" channels="2" bitrate="128" audioChannelLayout="stereo" samplingRate="48000" streamIdentifier="1" displayTitle="Unknown (MP3 Stereo)"/>
</Part>
</Media>
<Writer id="32583" filter="writer=32583" tag="Simon Schama"/>
<Extras size="0"> </Extras>
</Video>
</MediaContainer>
I should mention I see the same behavior on other AVI files. I tried to play an old copy of Good Eats, for instance, and got the same behavior.
