Linux PMS since V. 1.18 on Intel NUC video playing and transoding problem

Server Version#: 1.18.2.2041
Player Version#: 3.104.2
After 2 years of smooth playing with transcoding on a INTEL NUC, after installing Version 1.18X the playing and transcoding doesn’t work anymore. Videos don’t start and the Server logs raise VAPII errors. Unfortunately Plex doesn’t provider older 1.17 versions. Is it possible that you would sende me a link with an older working version (latest linux 64-bit Ubuntu PMS Version 1.17.x)
Many thanks and kind regards
Fehlmi

Logs capturing the errors?

Thanks.

Your CPU, the i3-4010U, does not need the iHD driver at all.

There is a workaround while the Transcoder team fixes this Intel-provided driver.

  1. Delete /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so
  2. Restart PMS.

Should you update PMS again before final repair to their driver, you’ll need delete it again.

ok. I’ll try that. many thanks. However is there an option go get an older pms version 1.17? (i didnt’ store older copies on my side)

Unfortunately, I can’t experience another behaviour… still the same Issue. Starting a movie not from the beginning is almost impossible (waiting time 10 minutes…)…
maybe I have to update. The old Bios from 2017…

Engineering never has allowed older versions and, at this point, is unlikely to ever allow it.

My best suggestion is to keep an older version yourself for just such events.

Get something you like , which is stable for you, and hang on to it for rainy days.

@fehlmi

I am going to need the full downloaded logs (Settings - Server - Troubleshooting - Download Logs),

which you collect after:

  1. Start playback
  2. Let run a few seconds
  3. Stop playback
  4. wait 20 seconds for logs to settle
  5. Download the ZIP file
  6. Attach it

This lets me see from the start through end of playback cycle, inclusive of any secondary decisions and errors.

Would you please enable DEBUG logging ?
Do not enable VERBOSE . It outputs too much information.
Now please attempt again.

Default is with DEBUG enabled.
It let’s us see what PMS is trying to do.

All I see is:

Nov 22, 2019 11:25:50.416 [0x7f104c937b80] INFO - OCSP: Successfully retrieved response from cache.
Nov 22, 2019 11:25:52.659 [0x7f102a5f9700] WARN - Crash: Crash reporting disabled
Nov 22, 2019 11:25:53.482 [0x7f10289d4700] INFO - Refreshing paths watched by LibraryUpdateManager
Nov 22, 2019 11:25:59.402 [0x7f102bfff700] INFO - AutoUpdate: no updates available
Nov 22, 2019 11:25:59.860 [0x7f100b7fe700] WARN - Sync: sync list 35704568 belonging to user 1 (fehlmi) has died of old age, ignoring
Nov 22, 2019 11:25:59.860 [0x7f100b7fe700] WARN - Sync: sync list 26822871 belonging to user 1 (fehlmi) has died of old age, ignoring
Nov 22, 2019 11:25:59.865 [0x7f100b7fe700] INFO - Sync: downloaded 1 sync list(s) with 5 sync items(s): 0 new, 0 updated, 0 deleted
Nov 22, 2019 11:28:08.201 [0x7f0fad7fa700] WARN - Timed out waiting for segment.
Nov 22, 2019 11:28:08.201 [0x7f0febfff700] WARN - Timed out waiting for segment.
Nov 22, 2019 11:30:08.808 [0x7f100b7fe700] WARN - Timed out waiting for segment.
Nov 22, 2019 11:30:09.616 [0x7f0fad7fa700] WARN - Timed out waiting for segment.
Nov 22, 2019 11:31:56.105 [0x7f0fcbfff700] ERROR - [Transcoder] [matroska,webm @ 0x1078680] Read error at pos. 6198018010 (0x1716e3fda)
Nov 22, 2019 11:32:09.936 [0x7f0febfff700] WARN - Timed out waiting for segment.
Nov 22, 2019 11:32:12.076 [0x7f100b7fe700] WARN - Timed out waiting for segment.
Nov 22, 2019 11:32:18.404 [0x7f0fad7fa700] WARN - Transcode runner appears to have died.
Nov 22, 2019 11:32:18.456 [0x7f0febfff700] WARN - Transcode runner appears to have died.
Nov 22, 2019 11:32:18.505 [0x7f0fad7fa700] WARN - Timed out waiting for segment.
Nov 22, 2019 11:32:18.556 [0x7f0febfff700] WARN - Timed out waiting for segment.
Nov 22, 2019 11:32:24.328 [0x7f0faffff700] WARN - Transcode runner appears to have died.
Nov 22, 2019 11:32:24.428 [0x7f0faffff700] WARN - Timed out waiting for segment.
Nov 22, 2019 11:32:28.562 [0x7f100b7fe700] WARN - Transcode runner appears to have died.
Nov 22, 2019 11:32:28.663 [0x7f100b7fe700] WARN - Timed out waiting for segment.
Nov 22, 2019 11:32:41.595 [0x7f100b7fe700] WARN - Transcode runner appears to have died.
Nov 22, 2019 11:32:41.696 [0x7f100b7fe700] WARN - Timed out waiting for segment.
Nov 22, 2019 11:32:42.281 [0x7f100b7fe700] WARN - Transcode runner appears to have died.

There is not enough information here to diagnose with.

Please attempt again – With VERBOSE turned OFF

(pipelined: 1) (range: bytes=0-) 
Nov 24, 2019 22:37:25.276 [0x7f1be2330700] VERBOSE - Auth: We found auth token (xxxxxxxxxxxxxxxxxxxx), enabling token-based authentication.
Nov 24, 2019 22:37:25.276 [0x7f1be2330700] VERBOSE - Auth: Came in with the master token, authorization succeeded.
Nov 24, 2019 22:37:25.277 [0x7f1bb4ff9700] DEBUG - Request: [127.0.0.1:59164 (Loopback)] PUT /video/:/transcode/session/ieg9y9oomha18jnm6u1st2c4/ddecba35-7d7f-45dd-9b26-6c1873fa35f9/progress?status=startup (11 live) Signed-in Token (fehlmi) (range: bytes=0-) 
Nov 24, 2019 22:37:25.277 [0x7f1bb4ff9700] VERBOSE -  * User-Agent => Lavf/58.27.103
Nov 24, 2019 22:37:25.277 [0x7f1bb4ff9700] VERBOSE -  * Accept => */*
Nov 24, 2019 22:37:25.277 [0x7f1bb4ff9700] VERBOSE -  * Range => bytes=0-
Nov 24, 2019 22:37:25.277 [0x7f1bb4ff9700] VERBOSE -  * Connection => keep-alive
Nov 24, 2019 22:37:25.277 [0x7f1bb4ff9700] VERBOSE -  * Host => 127.0.0.1:32400
Nov 24, 2019 22:37:25.277 [0x7f1bb4ff9700] VERBOSE -  * Icy-MetaData => 1
Nov 24, 2019 22:37:25.277 [0x7f1bb4ff9700] VERBOSE -  * X-Plex-Token => xxxxxxxxxxxxxxxxxxxx
Nov 24, 2019 22:37:25.277 [0x7f1bb4ff9700] VERBOSE -  * X-Plex-Http-Pipeline => infinite
Nov 24, 2019 22:37:25.277 [0x7f1bb4ff9700] VERBOSE -  * status => startup
Nov 24, 2019 22:37:25.277 [0x7f1be2330700] DEBUG - Completed: [127.0.0.1:59164] 204 PUT /video/:/transcode/session/ieg9y9oomha18jnm6u1st2c4/ddecba35-7d7f-45dd-9b26-6c1873fa35f9/progress?status=startup (11 live) 0ms 203 bytes (pipelined: 2) (range: bytes=0-) 

Thanks, That did it.

You are experiencing the iHD video driver issue.

The workaround is:

sudo rm /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so

Restart PMS

Nov 25, 2019 11:13:19.700 [0x7f1b54397700] WARN - Transcode runner appears to have died.
Nov 25, 2019 11:13:19.732 [0x7f1b767fc700] WARN - Transcode runner appears to have died.
Nov 25, 2019 11:14:34.349 [0x7f1b767fc700] ERROR - [FFMPEG] - libva: /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so init failed
Nov 25, 2019 11:14:34.349 [0x7f1b767fc700] ERROR - [FFMPEG] - Failed to initialise VAAPI connection: 1 (operation failed).
Nov 25, 2019 11:14:34.351 [0x7f1b767fc700] ERROR - [FFMPEG] - libva: /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so init failed
Nov 25, 2019 11:14:34.351 [0x7f1b767fc700] ERROR - [FFMPEG] - Failed to initialise VAAPI connection: 1 (operation failed).
Nov 25, 2019 11:14:34.685 [0x7f1b577fe700] ERROR - [FFMPEG] - libva: /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so init failed
Nov 25, 2019 11:14:34.685 [0x7f1b577fe700] ERROR - [FFMPEG] - Failed to initialise VAAPI connection: 1 (operation failed).
Nov 25, 2019 11:14:36.034 [0x7f1bd33dc700] ERROR - [FFMPEG] - libva: /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so init failed
Nov 25, 2019 11:14:36.034 [0x7f1bd33dc700] ERROR - [FFMPEG] - Failed to initialise VAAPI connection: 1 (operation failed).
Nov 25, 2019 11:14:43.850 [0x7f1be3332700] ERROR - [FFMPEG] - libva: /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so init failed
Nov 25, 2019 11:14:43.850 [0x7f1be3332700] ERROR - [FFMPEG] - Failed to initialise VAAPI connection: 1 (operation failed).
Nov 25, 2019 11:14:43.853 [0x7f1be3332700] ERROR - [FFMPEG] - libva: /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so init failed
Nov 25, 2019 11:14:43.853 [0x7f1be3332700] ERROR - [FFMPEG] - Failed to initialise VAAPI connection: 1 (operation failed).
Nov 25, 2019 11:14:43.858 [0x7f1be3332700] ERROR - [FFMPEG] - libva: /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so init failed
Nov 25, 2019 11:14:43.858 [0x7f1be3332700] ERROR - [FFMPEG] - Failed to initialise VAAPI connection: 1 (operation failed).
Nov 25, 2019 11:14:49.034 [0x7f1b77fff700] ERROR - [FFMPEG] - libva: /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so init failed
Nov 25, 2019 11:14:49.034 [0x7f1b77fff700] ERROR - [FFMPEG] - Failed to initialise VAAPI connection: 1 (operation failed).
Nov 25, 2019 11:14:49.037 [0x7f1b77fff700] ERROR - [FFMPEG] - libva: /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so init failed
Nov 25, 2019 11:14:49.037 [0x7f1b77fff700] ERROR - [FFMPEG] - Failed to initialise VAAPI connection: 1 (operation failed).
Nov 25, 2019 11:14:49.043 [0x7f1b77fff700] ERROR - [FFMPEG] - libva: /usr/lib/plexmediaserver/lib/dri/iHD_drv_video.so init failed
Nov 25, 2019 11:14:49.043 [0x7f1b77fff700] ERROR - [FFMPEG] - Failed to initialise VAAPI connection: 1 (operation failed).
Nov 25, 2019 11:14:53.016 [0x7f1be2330700] ERROR - Session 0x7f1b6c0bdb40 terminated

If you update PMS again before the Intel driver is fixed, you’ll need repeat this step

That corrected the nVidia issue.

Now let’s look at the group which owns the files in /dev/dri
Ubuntu 19.10 uses group render . Prior to this, it was group video.

The PMS installer was updated to detect the group and add itself to the current video group. This is done so udev will work correctly.

The log file is showing that no HW was found. This is the most common indication of a udev / group permission situation.

Nov 25, 2019 18:48:41.873 [0x7f7bcd7fa700] DEBUG - Cleaning directory for session 4822up2y26vaamkjpytfa26e ()
Nov 25, 2019 18:48:41.873 [0x7f7bcd7fa700] DEBUG - Starting a transcode session 4822up2y26vaamkjpytfa26e at offset -1.0 (state=3)
Nov 25, 2019 18:48:41.873 [0x7f7bcd7fa700] DEBUG - TPU: hardware transcoding: enabled, but no hardware decode accelerator found
Nov 25, 2019 18:48:41.873 [0x7f7bcd7fa700] DEBUG - [Universal] Using local file path instead of URL: /media/Spielfilme/Little 2019 German DL AC3 Dubbed 720p BluRay x264/pso-hd-little-720p.mkv
Nov 25, 2019 18:48:41.874 [0x7f7bcd7fa700] DEBUG - TPU: hardware transcoding: final decoder: , final encoder: 
Nov 25, 2019 18:48:41.874 [0x7f7bcd7fa700] DEBUG - Job running: EAE_ROOT='/tmp/pms-ea923f93-c825-409a-87e0-11750cdd27dc/EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/395e79c-2735-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/Plex Transcoder' '-codec:0' 'h264' '-codec:1' 'ac3' '-noaccurate_seek' '-analyzeduration' '20000000' '-probesize' '20000000' '-i' '/media/Spielfilme/Little 2019 German DL AC3 Dubbed 720p BluRay x264/pso-hd-little-720p.mkv' '-filter_complex' '[0:1] aresample=async=1:ocl='\''stereo'\'':osr=48000[0]' '-map' '0:0' '-metadata:s:0' 'language=eng' '-codec:0' 'copy' '-map' '[0]' '-metadata:s:1' 'language=ger' '-codec:1' 'aac' '-b:1' '256k' '-f' 'dash' '-seg_duration' '5' '-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/4822up2y26vaamkjpytfa26e/dcf43988-f39f-4f14-bc08-0d54f070da3d/manifest' '-avoid_negative_ts' 'disabled' '-map_metadata' '-1' '-map_chapters' '-1' 'dash' '-start_at_zero' '-copyts' '-vsync' 'cfr' '-y' '-nostats' '-loglevel' 'quiet' '-loglevel_plex' 'error' '-progressurl' 'http://127.0.0.1:32400/video/:/transcode/session/4822up2y26vaamkjpytfa26e/dcf43988-f39f-4f14-bc08-0d54f070da3d/progress'
Nov 25, 2019 18:48:41.874 [0x7f7bcd7fa700] DEBUG - Jobs: Starting child process with pid 5312

The content of /dev/dri in Ubuntu 18.04:
drwxr-xr-x 3 root root 100 Nov 24 22:31 .
drwxr-xr-x 19 root root 3940 Nov 24 22:31 …
drwxr-xr-x 2 root root 80 Nov 24 22:31 by-path
crw-rw---- 1 root video 226, 0 Nov 24 22:31 card0
crw-rw---- 1 root video 226, 128 Nov 24 22:31 renderD128

there are no other files. is that normal?

This is all good.

Now grep plex /etc/group

User plex should also be part of the video group.

adm:x:4:syslog,plexadmin
cdrom:x:24:plexadmin
sudo:x:27:plexadmin
dip:x:30:plexadmin
video:x:44:plex
plugdev:x:46:plexadmin
lxd:x:108:plexadmin
plexadmin:x:1000:
lpadmin:x:113:plexadmin
sambashare:x:114:plexadmin
plex:x:115:

User plex is not a member of the video group.

What is UID/GID Plex is running as?

plexadmin@Galaxy:/dev/dri$ id -u plex && id -g plex
111
115

plexadmin@Galaxy:/dev/dri$ id plex
uid=111(plex) gid=115(plex) Gruppen=115(plex),44(video)

plex is part of video group, isn’t it?

and the plex application runs under the user plex:
plex 5117 0.0 0.0 4628 920 ? Ss 18:47 0:00 /bin/sh -c PLEX_MEDIA_SERVER_INFO_VENDOR="(grep ^NAME= /etc/os-release | awk -F= "{print \$2}" | tr -d \" )" PLEX_MEDIA_SERVER_INFO_DEVICE="PC" PLEX_MEDIA_SERVER_INFO_MODEL="(uname -m)" PLEX_MEDIA_SERVER_INFO_PLATFORM_VERSION="$(grep ^VERSION= /etc/os-release | awk -F= “{print $2}” | tr -d " )" LD_LIBRARY_PATH=/usr/lib/plexmediaserver/lib “/usr/lib/plexmediaserver/Plex Media Server”
plex 5130 0.2 2.4 2511248 198680 ? Sl 18:47 0:22 /usr/lib/plexmediaserver/Plex Media Server
plex 5150 0.3 0.6 1793636 50340 ? SNl 18:47 0:30 Plex Plug-in [com.plexapp.system] /usr/lib/plexmediaserver/Resources/Plug-ins-e67a4e892/Framework.bundle/Contents/Resources/Versions/2/Python/bootstrap.py --server-version 1.18.2.2058-e67a4e892 /usr/lib/plexmediaserver/Resources/Plug-ins-e67a4e892/System.bundle
plex 5198 0.0 0.1 515812 14280 ? Sl 18:47 0:03 /usr/lib/plexmediaserver/Plex Tuner Service /usr/lib/plexmediaserver/Resources/Tuner/Private /usr/lib/plexmediaserver/Resources/Tune

My apologies, I misread.

plex = 111 / 115,44

Go deeper into the hardware sudo lshw > dummy.file

Now edit the file and look for the i915 chip and driver.

It should be something like my NUC (NUC8i7HVK)

        *-display
             description: Display controller
             product: HD Graphics 630
             vendor: Intel Corporation
             physical id: 2
             bus info: pci@0000:00:02.0
             version: 04
             width: 64 bits
             clock: 33MHz
             capabilities: pciexpress msi pm bus_master cap_list
             configuration: driver=i915 latency=0
             resources: iomemory:2f0-2ef iomemory:2f0-2ef irq:169 memory:2ffe000000-2ffeffffff memory:2fa0000000-2fafffffff ioport:f000(size=64)

Make sure it isn’t disabled in the UEFI as well. Something isn’t right in the config

*-display
description: VGA compatible controller
product: Haswell-ULT Integrated Graphics Controller
vendor: Intel Corporation
physical id: 2
bus info: pci@0000:00:02.0
version: 09
width: 64 bits
clock: 33MHz
capabilities: msi pm vga_controller bus_master cap_list rom
configuration: driver=i915 latency=0
resources: irq:45 memory:f7800000-f7bfffff memory:e0000000-efffffff ioport:f000(size=64) memory:c0000-dffff

I will check the bios as well.

I’ve verified the bios. there is no option to deactivate the onboard graphic. It runs normally connected to a display via HDMI.