Error code: s1003 (Network) (HW transcode failing - SOLVED)

Plex Media Server Desktops & Laptops
1

Server Version#: 1.24.3.5033
Player Version#: 4.66.1

I just upgraded my ubuntu server, and now I’m getting a s1003 error when trying to play a lot of the videos (but some play fine, and it seems to be consistent which one do and doesn’t play).

plex_web_error_s1003
plex_web_error_s1003700×386 11.6 KB

after this happens (closing the dialog box above and not doing anything else) there are several processes on the server running at 100% and they don’t appear to end on their own, requiring a restart of the plexmediaserver service.

plex_after_buffy_started
plex_after_buffy_started1447×664 81.3 KB

UPNP is turned off at the router.
Plex runs directly on the os, not virtual/container.
The files are definitely readable and available (accessed through a nfs share from the NAS).

on server startup this is in the system.log:

2021-09-28 09:51:50,011 (7fdc21df2b38) :  CRITICAL (storage:60) - Exception reading file /usr/lib/plexmediaserver/Resources/Plug-ins-757abe6b4/WebClient.bundle/Contents/Info.plist (most recent call last):
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-757abe6b4/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/storage.py", line 55, in load
    f = open(filename, mode)
IOError: [Errno 2] No such file or directory: '/usr/lib/plexmediaserver/Resources/Plug-ins-757abe6b4/WebClient.bundle/Contents/Info.plist'

2021-09-28 09:51:50,012 (7fdc21df2b38) :  CRITICAL (bundleservice:141) - Exception adding bundle: WebClient.bundle (most recent call last):
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-757abe6b4/System.bundle/Contents/Code/bundleservice.py", line 131, in update_bundles
    Log('Found duplicate identifier at %s for bundled plugin (%s), ignoring duplicate plugin.' % (path, bundle.identifier))
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-757abe6b4/System.bundle/Contents/Code/bundleservice.py", line 18, in __init__
    self.load_plist()
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-757abe6b4/System.bundle/Contents/Code/bundleservice.py", line 22, in load_plist
    plist = Plist.ObjectFromString(Core.storage.load(Core.storage.join_path(self.path, "Contents", "Info.plist")))
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-757abe6b4/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/parsekit.py", line 32, in ObjectFromString
    check_size(string, max_size)
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-757abe6b4/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/api/parsekit.py", line 22, in check_size
    if len(data) > max_size:
TypeError: object of type 'NoneType' has no len()

For a video that does work the logs say this about the transcoding:

Sep 28, 2021 09:52:33.478 [0x7fb2ca5a7b38] DEBUG - Request: [192.168.1.110:62906 (Subnet)] GET /video/:/transcode/universal/decision?hasMDE=1&path=%2Flibrary%2Fmetadata%2F12496&mediaIndex=0&partIndex=0&protocol=dash&fastSeek=1&directPlay=0&directStream=1&subtitleSize=100&audioBoost=100&location=lan&addDebugOverlay=0&autoAdjustQuality=0&directStreamAudio=1&mediaBufferSize=102400&session=9w1klh2c038bqjll7104rfj9&subtitles=burn&Accept-Language=en (10 live) TLS GZIP Signed-in Token (erlendaakre)
Sep 28, 2021 09:52:33.479 [0x7fb2ca5a7b38] DEBUG - [Transcode] Found session GUID of 9w1klh2c038bqjll7104rfj9 in session start.
Sep 28, 2021 09:52:33.480 [0x7fb2ca5a7b38] DEBUG - [Transcode] TranscodeUniversalRequest: using augmented profile Web
Sep 28, 2021 09:52:33.480 [0x7fb2ca5a7b38] DEBUG - [Transcode] Downloading document http://127.0.0.1:32400/library/metadata/12496?includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=yxyh03haujgvrv6kq3ute83k
Sep 28, 2021 09:52:33.493 [0x7fb2ca5a7b38] DEBUG - [Transcode] We're going to try to auto-select an audio stream for account 1.
Sep 28, 2021 09:52:33.493 [0x7fb2ca5a7b38] DEBUG - [Transcode] Selecting best audio stream for part ID 19803 (autoselect: 1 language: en)
Sep 28, 2021 09:52:33.493 [0x7fb2ca5a7b38] DEBUG - [Transcode] Audio Stream: 28454, Subtitle Stream: -1
Sep 28, 2021 09:52:33.496 [0x7fb2ca5a7b38] DEBUG - [Transcode] MDE: Selected protocol dash; container: mp4
Sep 28, 2021 09:52:33.496 [0x7fb2ca5a7b38] DEBUG - [Transcode] MDE: analyzing media item 19632
Sep 28, 2021 09:52:33.496 [0x7fb2ca5a7b38] DEBUG - [Transcode] MDE: E9 - Scorched Earth: Direct Play is disabled
Sep 28, 2021 09:52:33.496 [0x7fb2ca5a7b38] DEBUG - [Transcode] MDE: E9 - Scorched Earth: media must be transcoded in order to use the dash protocol
Sep 28, 2021 09:52:33.496 [0x7fb2ca5a7b38] DEBUG - [Transcode] MDE: E9 - Scorched Earth: no direct play video profile exists for http/mkv/h264
Sep 28, 2021 09:52:33.496 [0x7fb2ca5a7b38] DEBUG - [Transcode] MDE: E9 - Scorched Earth: no direct play video profile exists for http/mkv/h264/ac3
Sep 28, 2021 09:52:33.496 [0x7fb2ca5a7b38] DEBUG - [Transcode] MDE: E9 - Scorched Earth: no direct play video profile exists for http/mkv/h264/aac
Sep 28, 2021 09:52:33.496 [0x7fb2ca5a7b38] DEBUG - [Transcode] MDE: Cannot direct stream audio stream due to codec ac3 when profile only allows aac
Sep 28, 2021 09:52:33.496 [0x7fb2ca5a7b38] DEBUG - [Transcode] MDE: Stargate SG-1 - S4 E9 - Scorched Earth: selected media 0 / 19632
Sep 28, 2021 09:52:33.496 [0x7fb2ca5a7b38] DEBUG - [Transcode] Streaming Resource: Added session 0x7fb2cac29618:yxyh03haujgvrv6kq3ute83k
Sep 28, 2021 09:52:33.497 [0x7fb2ca5a7b38] DEBUG - [Transcode] Streaming Resource: Reached Decision id=12496 codes=(General=1001,Direct pla

But for the second one that fails, there are two errors:

Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] ERROR - [Transcode] [FFMPEG] - libva: vaGetDriverNameByIndex() failed with unknown libva error, driver_name = (null)
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] ERROR - [Transcode] [FFMPEG] - Failed to initialise VAAPI connection: -1 (unknown libva error).

Sep 28, 2021 09:57:05.884 [0x7fb2ca920b38] DEBUG - Request: [192.168.1.110:64606 (Subnet)] GET /video/:/transcode/universal/decision?hasMDE=1&path=%2Flibrary%2Fmetadata%2F13015&mediaIndex=0&partIndex=0&protocol=dash&fastSeek=1&directPlay=0&directStream=1&subtitleSize=100&audioBoost=100&location=lan&addDebugOverlay=0&autoAdjustQuality=0&directStreamAudio=1&mediaBufferSize=102400&session=g81uc4t5gdgcw8lr2rf2b5kx&subtitles=burn&Accept-Language=en (6 live) TLS GZIP Signed-in Token (erlendaakre)
Sep 28, 2021 09:57:05.885 [0x7fb2ca920b38] DEBUG - [Transcode] Found session GUID of g81uc4t5gdgcw8lr2rf2b5kx in session start.
Sep 28, 2021 09:57:05.885 [0x7fb2ca920b38] DEBUG - [Transcode] TranscodeUniversalRequest: using augmented profile Web
Sep 28, 2021 09:57:05.885 [0x7fb2ca920b38] DEBUG - [Transcode] Downloading document http://127.0.0.1:32400/library/metadata/13015?includeBandwidths=1&offset=-1&X-Plex-Incomplete-Segments=1&X-Plex-Session-Identifier=syk5rmmq1o19y2qfesz6prai
Sep 28, 2021 09:57:05.891 [0x7fb2ca920b38] DEBUG - [Transcode] We're going to try to auto-select an audio stream for account 1.
Sep 28, 2021 09:57:05.891 [0x7fb2ca920b38] DEBUG - [Transcode] Selecting best audio stream for part ID 20317 (autoselect: 1 language: en)
Sep 28, 2021 09:57:05.891 [0x7fb2ca920b38] DEBUG - [Transcode] Audio Stream: 29800, Subtitle Stream: -1
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] Codecs: testing h264_vaapi (encoder)
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API vaapi
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] ERROR - [Transcode] [FFMPEG] - libva: vaGetDriverNameByIndex() failed with unknown libva error, driver_name = (null)
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] ERROR - [Transcode] [FFMPEG] - Failed to initialise VAAPI connection: -1 (unknown libva error).
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] Codecs: hardware transcoding: opening hw device failed - probably not supported by this system, error: I/O error
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] Codecs: testing h264_nvenc (encoder)
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] Codecs: hardware transcoding: testing API nvenc
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded lib: libcuda.so.1
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuInit
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuDeviceGetCount
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuDeviceGet
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuDeviceGetAttribute
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuDeviceGetName
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuDeviceComputeCapability
Sep 28, 2021 09:57:05.892 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuCtxCreate_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuCtxSetLimit
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuCtxPushCurrent_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuCtxPopCurrent_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuCtxDestroy_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuMemAlloc_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuMemAllocPitch_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuMemsetD8Async
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuMemFree_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuMemcpy2D_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuMemcpy2DAsync_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuGetErrorName
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuGetErrorString
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuCtxGetDevice
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuStreamCreate
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuStreamQuery
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuStreamSynchronize
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuStreamDestroy_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuStreamAddCallback
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuEventCreate
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuEventDestroy_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuEventSynchronize
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuEventQuery
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuEventRecord
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuLaunchKernel
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuLinkCreate
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuLinkAddData
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuLinkComplete
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuLinkDestroy
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuModuleLoadData
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuModuleUnload
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuModuleGetFunction
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuTexObjectCreate
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuTexObjectDestroy
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuGLGetDevices_v2
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuGraphicsGLRegisterImage
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuGraphicsUnregisterResource
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuGraphicsMapResources
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuGraphicsUnmapResources
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuGraphicsSubResourceGetMappedArray
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Cannot load optional cuDeviceGetUuid
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Cannot load optional cuImportExternalMemory
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Cannot load optional cuDestroyExternalMemory
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Cannot load optional cuExternalMemoryGetMappedBuffer
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Cannot load optional cuExternalMemoryGetMappedMipmappedArray
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuMipmappedArrayGetLevel
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Loaded sym: cuMipmappedArrayDestroy
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Cannot load optional cuImportExternalSemaphore
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Cannot load optional cuDestroyExternalSemaphore
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Cannot load optional cuSignalExternalSemaphoresAsync
Sep 28, 2021 09:57:05.893 [0x7fb2ca920b38] DEBUG - [Transcode] [FFMPEG] - Cannot load optional cuWaitExternalSemaphoresAsync

Anyone got a clue on what might be causing this?
The same episodes were playing just fine before I upgraded ubuntu.

Full log file:
Successful video playback at 09:52.
Failed video playback at 09:57.
Plex Media Server.log (363.7 KB)

2

Solved.

Upgrading to the latest Nvidia drivers (470) did the trick, server is now back to it’s good old self. leaving the post in case anyone has the same error

4

Thanks for posting this; it’d been driving me crazy for a few weeks and I finally got around to looking at it. Updating Nvidia drivers from 340 (I think) to 470 followed by a restart did the trick.

For anyone unsure where to do this, open Ubuntu’s software updater and find the “Additional Drivers” section.

5

So am I understanding this correctly? My plex server that has been running fine for several years now requires a VIDEO CARD upgrade so I can play my existing files? My video card is not supported by recent drivers and I have no desire to buy a new one.

Would someone kindly clarify this please? I have had a “Lifetime Plex Pass” for as long as I can remember and I have never ran into an issue such as this before.

If necessary, how do I roll-back to a working version? I just noticed this recently. I have no idea how long ago the change was implemented.

I tried moving to plexmediaserver_1.25.0.5246-cb2507e4d_amd64.deb but it does not seem to have made a difference.

6

@koakawe

Please explain the hardware you have.
Also please show the DEBUG log files which have captured your problem.

What you’ve stated here isn’t enough to even answer properly.

8

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