Server Does Not Play Any Media

Plex Media Server
1

Server Version#: 1.26.0.5715
Player Version#: {various. Does not play on any platform}

I am able to connect to Plex and see content, but nothing plays. Some storage is local and some remote (mounted). Regardless of location, nothing plays. When I select anything to play, the busy indicator spins for a while, then I get a “content is unavailable” message. Occasionally, if I do this enough, then Plex disconnects and I need to reboot the server. Using systemctl to restart the plexmedia service takes a long time. Much longer than normal.

I checked the integrity of databases and they all show ok.

Nothing changed prior to the issue. No server OS updates, no Plex updates. However, I did upgrade plex to the latest build yesterday. It was only one build behind.

I do see dozens and dozens of entries in the logs that state “Now watching”. I have no idea what that means. Nothing is or can be watched… I assume that means that Plex is watching those folders…

This seems to be an issue. Entries from the agents.imdb.log. Not sure if it is related to this issue:

2022-05-14 06:47:51,656 (7f3ff4c2c808) :  INFO (core:349) - Starting framework core - Version: 2.6.3, Build: 8cf78da (Mon Apr 04 16:28:06 UTC 2022)
2022-05-14 06:47:51,657 (7f3ff4c2c808) :  DEBUG (core:361) - Using the elevated policy
2022-05-14 06:47:51,657 (7f3ff4c2c808) :  DEBUG (core:450) - Starting runtime component.
2022-05-14 06:47:51,658 (7f3ff4c2c808) :  DEBUG (core:450) - Starting caching component.
2022-05-14 06:47:51,658 (7f3ff4c2c808) :  DEBUG (core:450) - Starting data component.
2022-05-14 06:47:51,658 (7f3ff4c2c808) :  DEBUG (core:450) - Starting networking component.
2022-05-14 06:47:51,658 (7f3ff4c2c808) :  DEBUG (networking:261) - Loaded HTTP cookies
2022-05-14 06:47:51,660 (7f3ff4c2c808) :  DEBUG (networking:428) - Setting the default network timeout to 20.0
2022-05-14 06:47:51,660 (7f3ff4c2c808) :  DEBUG (core:450) - Starting localization component.
2022-05-14 06:47:51,660 (7f3ff4c2c808) :  INFO (localization:409) - Setting the default locale to en-us
2022-05-14 06:47:51,660 (7f3ff4c2c808) :  DEBUG (core:450) - Starting messaging component.
2022-05-14 06:47:51,660 (7f3ff4c2c808) :  DEBUG (core:450) - Starting debugging component.
2022-05-14 06:47:51,661 (7f3ff4c2c808) :  DEBUG (core:450) - Starting services component.
2022-05-14 06:47:51,661 (7f3ff4c2c808) :  DEBUG (core:450) - Starting myplex component.
2022-05-14 06:47:51,661 (7f3ff4c2c808) :  DEBUG (core:450) - Starting notifications component.
2022-05-14 06:47:51,661 (7f3ff1a3fb38) :  DEBUG (networking:143) - Requesting 'http://127.0.0.1:32400/system/messaging/clear_events/com.plexapp.agents.imdb'
2022-05-14 06:47:51,765 (7f3ff4c2c808) :  DEBUG (accessor:68) - Creating a new model access point for provider com.plexapp.agents.imdb in namespace 'metadata'
2022-05-14 06:47:51,769 (7f3ff4c2c808) :  DEBUG (networking:143) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/resourceHashes'
2022-05-14 06:47:52,247 (7f3ff4c2c808) :  ERROR (networking:196) - Error opening URL 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/resourceHashes'
2022-05-14 06:47:52,248 (7f3ff4c2c808) :  CRITICAL (runtime:1299) - Exception getting hosted resource hashes (most recent call last):
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-8cf78dab3/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/runtime.py", line 1293, in get_resource_hashes
    json = self._core.networking.http_request("http://127.0.0.1:32400/:/plugins/com.plexapp.system/resourceHashes", timeout=10).content
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-8cf78dab3/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py", line 242, in content
    return self.__str__()
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-8cf78dab3/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py", line 220, in __str__
    self.load()
  File "/usr/lib/plexmediaserver/Resources/Plug-ins-8cf78dab3/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/networking.py", line 158, in load
    f = self._opener.open(req, timeout=self._timeout)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 435, in open
    response = meth(req, response)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 548, in http_response
    'http', request, response, code, msg, hdrs)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 473, in error
    return self._call_chain(*args)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 407, in _call_chain
    result = func(*args)
  File "/usr/lib/plexmediaserver/Resources/Python/python27.zip/urllib2.py", line 556, in http_error_default
    raise HTTPError(req.get_full_url(), code, msg, hdrs, fp)
HTTPError: HTTP Error 404: Not Found

2022-05-14 06:47:52,255 (7f3ff4c2c808) :  DEBUG (runtime:1117) - Created a thread named 'load_all_services'
2022-05-14 06:47:52,255 (7f3ff16edb38) :  DEBUG (services:265) - Plug-in is not daemonized - loading services from system
2022-05-14 06:47:52,256 (7f3ff4c2c808) :  DEBUG (runtime:1117) - Created a thread named 'get_server_info'
2022-05-14 06:47:52,256 (7f3ff4c2c808) :  DEBUG (core:150) - Finished starting framework core
2022-05-14 06:47:52,256 (7f3ff16a0b38) :  DEBUG (networking:143) - Requesting 'http://127.0.0.1:32400'
2022-05-14 06:47:52,256 (7f3ff4c2c808) :  DEBUG (core:560) - Loading plug-in code
2022-05-14 06:47:52,256 (7f3ff16edb38) :  DEBUG (networking:143) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X0J1bmRsZVNlcnZpY2U6QWxsU2VydmljZXM_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMApyMAo_'
2022-05-14 06:47:52,301 (7f3ff16a0b38) :  DEBUG (core:538) - Machine identifier is 29c9d954bf02d58393ea84ae16b0ef0020c66be0
2022-05-14 06:47:52,301 (7f3ff16a0b38) :  DEBUG (core:539) - Server version is 1.26.0.5715-8cf78dab3
2022-05-14 06:47:52,542 (7f3ff16edb38) :  DEBUG (services:362) - Loaded services
2022-05-14 06:47:52,595 (7f3ff16cab38) :  DEBUG (services:438) - No shared code to load
2022-05-14 06:47:52,761 (7f3ff4c2c808) :  DEBUG (core:566) - Finished loading plug-in code
2022-05-14 06:47:52,852 (7f3ff4c2c808) :  DEBUG (agentkit:1132) - Creating new agent class called PlexMovieAgent
2022-05-14 06:47:52,853 (7f3ff4c2c808) :  DEBUG (agentkit:937) - Updating agent information: [{'media_types': ['Movie'], 'accepts_from': ['com.plexapp.agents.localmedia'], 'fallback_agent': None, 'contributes_to': ['com.plexapp.agents.themoviedb'], 'languages': ['en', 'sv', 'fr', 'es', 'nl', 'de', 'it', 'da', 'ar', 'ca', 'zh', 'cs', 'et', 'fi', 'el', 'he', 'hi', 'hu', 'id', 'ja', 'ko', 'lv', 'no', 'fa', 'pl', 'pt', 'ro', 'ru', 'sk', 'th', 'tr', 'uk', 'vi'], 'persist_stored_files': True, 'version': 0, 'primary_provider': True, 'prefs': True, 'name': 'Plex Movie'}]
2022-05-14 06:47:52,854 (7f3ff4c2c808) :  DEBUG (networking:143) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X0FnZW50U2VydmljZTpVcGRhdGVJbmZv/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQo3CmRpY3QKbGlzdApkaWN0Cmxpc3QKbGlzdApsaXN0Cmxpc3QKMgpzMjMKY29tLnBsZXhhcHAuYWdlbnRzLmltZGJzMTAKaWRlbnRpZmllcnIxCnMxMAphZ2VudF9pbmZvMQpyMgoxMApyMwpzMTEKbWVkaWFfdHlwZXNyNApzMTIKYWNjZXB0c19mcm9tbnMxNApmYWxsYmFja19hZ2VudHI1CnMxNApjb250cmlidXRlc190b3I2CnM5Cmxhbmd1YWdlc2IxczIwCnBlcnNpc3Rfc3RvcmVkX2ZpbGVzaTAKczcKdmVyc2lvbmIxczE2CnByaW1hcnlfcHJvdmlkZXJiMXM1CnByZWZzczEwClBsZXggTW92aWVzNApuYW1lMQpzNQpNb3ZpZTEKczI5CmNvbS5wbGV4YXBwLmFnZW50cy5sb2NhbG1lZGlhMQpzMjkKY29tLnBsZXhhcHAuYWdlbnRzLnRoZW1vdmllZGIzMwpzMgplbnMyCnN2czIKZnJzMgplc3MyCm5sczIKZGVzMgppdHMyCmRhczIKYXJzMgpjYXMyCnpoczIKY3NzMgpldHMyCmZpczIKZWxzMgpoZXMyCmhpczIKaHVzMgppZHMyCmphczIKa29zMgpsdnMyCm5vczIKZmFzMgpwbHMyCnB0czIKcm9zMgpydXMyCnNrczIKdGhzMgp0cnMyCnVrczIKdmlyMAo_'
2022-05-14 06:47:52,859 (7f3ff4c2c808) :  INFO (core:611) - Started plug-in
2022-05-14 06:47:52,859 (7f3ff4c2c808) :  DEBUG (socketinterface:160) - Starting socket server
2022-05-14 06:47:52,859 (7f3ff4c2c808) :  DEBUG (runtime:1117) - Created a thread named 'start'
2022-05-14 06:47:52,859 (7f3ff4c2c808) :  INFO (socketinterface:184) - Socket server started on port 38407
2022-05-14 06:47:52,860 (7f3ff4c2c808) :  INFO (pipeinterface:25) - Entering run loop
2022-05-14 06:47:52,860 (7f3ff4c2c808) :  DEBUG (runtime:717) - Handling request GET /:/prefixes
2022-05-14 06:47:52,860 (7f3ff4c2c808) :  DEBUG (runtime:814) - Found route matching /:/prefixes
2022-05-14 06:47:52,861 (7f3ff4c2c808) :  DEBUG (runtime:924) - Response: [200] MediaContainer, 148 bytes
2022-05-14 06:47:52,862 (7f3ff15f9b38) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.agents.imdb/prefs
2022-05-14 06:47:52,868 (7f3ff15f9b38) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.agents.imdb/prefs
2022-05-14 06:47:52,869 (7f3ff15f9b38) :  DEBUG (preferences:258) - Loaded preferences from DefaultPrefs.json
2022-05-14 06:47:52,869 (7f3ff15f9b38) :  DEBUG (preferences:178) - Loaded the user preferences for com.plexapp.agents.imdb
2022-05-14 06:47:52,872 (7f3ff15f9b38) :  DEBUG (runtime:88) - Sending packed state data (104 bytes)
2022-05-14 06:47:52,872 (7f3ff15f9b38) :  DEBUG (runtime:924) - Response: [200] MediaContainer, 2220 bytes





Below is info from the server log after restart:

May 14, 2022 06:47:48.986 [0x7f8720723b38] INFO - Plex Media Server v1.26.0.5715-8cf78dab3 - Ubuntu PC x86_64 - build: linux-x86_64 debian - GMT -07:00
May 14, 2022 06:47:48.988 [0x7f8720723b38] INFO - Linux version: 20.04.4 LTS (Focal Fossa), language: en-US
May 14, 2022 06:47:48.988 [0x7f8720723b38] INFO - Processor: 8-core Intel(R) Xeon(R) CPU E3-1245 v6 @ 3.70GHz
May 14, 2022 06:47:48.988 [0x7f8720723b38] INFO - Compiler is - Clang 11.0.1 (https://plex.tv b587490162c22e078c314e3f7dc560c691d126aa)
May 14, 2022 06:47:48.988 [0x7f8720723b38] INFO - /usr/lib/plexmediaserver/Plex Media Server
May 14, 2022 06:47:48.989 [0x7f87207ded48] DEBUG - BPQ: [Idle] -> [Starting]
May 14, 2022 06:47:48.989 [0x7f87207ded48] VERBOSE - BPQ: delaying processing 120 second(s)
May 14, 2022 06:47:48.989 [0x7f87207ded48] DEBUG - FeatureManager: Using cached data for features list
May 14, 2022 06:47:48.991 [0x7f87207ded48] DEBUG - Opening 20 database sessions to library (com.plexapp.plugins.library), SQLite 3.35.5, threadsafe=1
May 14, 2022 06:47:48.994 [0x7f87207ded48] INFO - SQLITE3:0x80000001, 283, recovered 15 frames from WAL file /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-in Support/Databases/com.plexapp.plugins.library.db-wal
May 14, 2022 06:47:49.027 [0x7f87207ded48] DEBUG - Running migrations. (EPG 0)
May 14, 2022 06:47:49.061 [0x7f87207ded48] DEBUG - ChangestampAllocator: initialized to 141539578
May 14, 2022 06:47:49.482 [0x7f87207ded48] DEBUG - Opening 2 database sessions to library (com.plexapp.plugins.library.blobs), SQLite 3.35.5, threadsafe=1
May 14, 2022 06:47:49.484 [0x7f87207ded48] INFO - SQLITE3:0x80000001, 283, recovered 129 frames from WAL file /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-in Support/Databases/com.plexapp.plugins.library.blobs.db-wal
May 14, 2022 06:47:49.487 [0x7f87207ded48] DEBUG - Running migrations. (EPG 0)
May 14, 2022 06:47:49.487 [0x7f87207ded48] VERBOSE - [FFMPEG] - Rescanning for external libs: '/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/994f4ee-4285-linux-x86_64/'
May 14, 2022 06:47:49.488 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libmp2_decoder.so
May 14, 2022 06:47:49.489 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libmp3_decoder.so
May 14, 2022 06:47:49.489 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libaac_decoder.so
May 14, 2022 06:47:49.491 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libac3_encoder.so
May 14, 2022 06:47:49.491 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libhevc_decoder.so
May 14, 2022 06:47:49.493 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/liblibx264_encoder.so
May 14, 2022 06:47:49.494 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/liblibmp3lame_encoder.so
May 14, 2022 06:47:49.495 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libvp9_decoder.so
May 14, 2022 06:47:49.496 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libmpeg4_decoder.so
May 14, 2022 06:47:49.497 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libmsmpeg4v2_decoder.so
May 14, 2022 06:47:49.498 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libwmav2_decoder.so
May 14, 2022 06:47:49.499 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libwmv3_decoder.so
May 14, 2022 06:47:49.500 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libmpeg2video_decoder.so
May 14, 2022 06:47:49.501 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libdca_decoder.so
May 14, 2022 06:47:49.502 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libvc1_decoder.so
May 14, 2022 06:47:49.503 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libaac_encoder.so
May 14, 2022 06:47:49.504 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libh264_decoder.so
May 14, 2022 06:47:49.506 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libmsmpeg4v3_decoder.so
May 14, 2022 06:47:49.507 [0x7f87207ded48] VERBOSE - [FFMPEG] - Loading external lib /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Codecs/994f4ee-4285-linux-x86_64/libac3_decoder.so
May 14, 2022 06:47:49.519 [0x7f87207ded48] DEBUG - [CERT] Subject name is /CN=*.b28f462d535643b8ac5cda07a5480b51.plex.direct
May 14, 2022 06:47:49.519 [0x7f87207ded48] DEBUG - [CERT] Installed certificate with fingerprint bf:16:34:60:d5:bb:3f:dc:47:13:34:46:d3:f8:30:6c:ca:17:dd:f1.
May 14, 2022 06:47:49.519 [0x7f87207ded48] DEBUG - [CERT/OCSP] Stapling requests will be made to 'http://r3.o.lencr.org/'.
May 14, 2022 06:47:49.519 [0x7f87207ded48] VERBOSE - [CERT/OCSP] Successfully generated stapling request
May 14, 2022 06:47:49.520 [0x7f87207ded48] INFO - [CERT/OCSP] Successfully retrieved response from cache.
May 14, 2022 06:47:49.520 [0x7f87207ded48] DEBUG - HttpServer: Listening on IPv6 as well as IPv4.
May 14, 2022 06:47:49.520 [0x7f87207ded48] DEBUG - HttpServer: Listening on port 32400.
May 14, 2022 06:47:49.520 [0x7f87207ded48] DEBUG - HttpServer: Listening on port 32401.
May 14, 2022 06:47:49.553 [0x7f871e640b38] DEBUG - Grabber: Cleaning up orphaned grabs.
May 14, 2022 06:47:49.555 [0x7f871e3afb38] DEBUG - MyPlex: mapping state set to 'Unknown'.
May 14, 2022 06:47:49.555 [0x7f87207ded48] DEBUG - Media Provider: Registering provider com.plexapp.plugins.library
May 14, 2022 06:47:49.555 [0x7f87207ded48] DEBUG - Auth: Refreshing tokens inside the token-based authentication filter.
May 14, 2022 06:47:49.558 [0x7f871e3afb38] DEBUG - Relay: read 115 cached entries from hosts file
May 14, 2022 06:47:49.559 [0x7f871e3afb38] DEBUG - [MediaProviderManager] HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:49.559 [0x7f87207ded48] DEBUG - MyPlex: using cached data for request for https://plex.tv/api/v2/server/access_tokens?auth_token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:49.562 [0x7f87207ded48] DEBUG - MyPlex: updating with 52 access tokens
May 14, 2022 06:47:49.570 [0x7f87207ded48] DEBUG - MyPlex: using cached data for request for https://plex.tv/api/v2/server/users?auth_token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:49.572 [0x7f87207ded48] DEBUG - MyPlex: using cached data for request for https://plex.tv/api/v2/server/users/subscriptions?auth_token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:49.576 [0x7f87207ded48] DEBUG - Opening 1 database sessions to library (), SQLite 3.35.5, threadsafe=1
May 14, 2022 06:47:49.578 [0x7f871e02eb38] DEBUG - File "/usr/lib/plexmediaserver/Resources/Plug-ins-8cf78dab3" changed: -1 => 2022-05-13 21:12:42 (1652501562).
May 14, 2022 06:47:49.578 [0x7f871e02eb38] DEBUG - File "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-ins" changed: -1 => 2018-12-15 12:05:10 (1544904310).
May 14, 2022 06:47:49.578 [0x7f871e02eb38] DEBUG - Scanning for plug-ins in "/usr/lib/plexmediaserver/Resources/Plug-ins-8cf78dab3"
May 14, 2022 06:47:49.592 [0x7f871e02eb38] DEBUG - Scanning for plug-ins in "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-ins"
May 14, 2022 06:47:49.594 [0x7f871e02eb38] DEBUG - PluginRepository::setStartState: 1, startingSystem
May 14, 2022 06:47:49.594 [0x7f871e02eb38] DEBUG - Starting plug-in /usr/lib/plexmediaserver/Resources/Plug-ins-8cf78dab3/System.bundle.
May 14, 2022 06:47:49.595 [0x7f871e02eb38] DEBUG - [com.plexapp.system] Setting plug-in to always running (daemon mode).
May 14, 2022 06:47:49.596 [0x7f871e02eb38] DEBUG - Starting file watcher for com.plexapp.system
May 14, 2022 06:47:49.596 [0x7f871e02eb38] DEBUG - Plugin: setting environment variable: 'PYTHONHOME=/usr/lib/plexmediaserver/Resources/Python'
May 14, 2022 06:47:49.597 [0x7f871e02eb38] DEBUG - Plugin: setting environment variable: 'PYTHONPATH=/usr/lib/plexmediaserver/Resources/Python/python27.zip:/usr/lib/plexmediaserver/Resources/Python/lib/python2.7/site-packages'
May 14, 2022 06:47:49.597 [0x7f871e02eb38] DEBUG - Spawned plug-in com.plexapp.system with PID 1148
May 14, 2022 06:47:49.597 [0x7f871e02eb38] DEBUG - [com.plexapp.system] Sending command: GET /:/prefixes
May 14, 2022 06:47:49.600 [0x7f871e218b38] DEBUG - Auth: Refreshing tokens inside the token-based authentication filter.
May 14, 2022 06:47:49.600 [0x7f871e218b38] DEBUG - HTTP requesting GET https://plex.tv/api/v2/server/access_tokens?auth_token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:50.183 [0x7f871e37bb38] DEBUG - [HttpClient] HTTP/2.0 (0.6s) 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:50.183 [0x7f871e3afb38] DEBUG - [MediaProviderManager] HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:50.222 [0x7f871e640b38] DEBUG - Grabber: Cleaned up 0 decrepit directories in 0.1 sec.
May 14, 2022 06:47:50.362 [0x7f871e37bb38] DEBUG - [HttpClient] HTTP/2.0 (0.2s) 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx (reused)
May 14, 2022 06:47:50.362 [0x7f871e3afb38] DEBUG - [MediaProviderManager] discovered cloud provider (Movies & TV)
May 14, 2022 06:47:50.362 [0x7f871e3afb38] DEBUG - [MediaProviderManager] discovered cloud provider (Music)
May 14, 2022 06:47:50.362 [0x7f871e3afb38] DEBUG - [MediaProviderManager] discovered cloud provider (Metadata)
May 14, 2022 06:47:50.362 [0x7f871e3afb38] DEBUG - [MediaProviderManager] loading cloud provider details (Metadata) (alive: 0)
May 14, 2022 06:47:50.362 [0x7f871e146b38] DEBUG - [MediaProviderManager] HTTP requesting GET https://vod.provider.plex.tv
May 14, 2022 06:47:50.362 [0x7f871e123b38] DEBUG - [MediaProviderManager] HTTP requesting GET https://music.provider.plex.tv
May 14, 2022 06:47:50.462 [0x7f871e37bb38] DEBUG - [HttpClient] HTTP/2.0 (0.9s) 200 response from GET https://plex.tv/api/v2/server/access_tokens?auth_token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:50.463 [0x7f871e218b38] DEBUG - MyPlex: updating with 52 access tokens
May 14, 2022 06:47:50.464 [0x7f871e218b38] DEBUG - HTTP requesting GET https://plex.tv/api/v2/server/users?auth_token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:50.465 [0x7f871e37bb38] DEBUG - [HttpClient] HTTP/2.0 (0.1s) 200 response from GET https://vod.provider.plex.tv
May 14, 2022 06:47:50.479 [0x7f871e37bb38] DEBUG - [HttpClient] HTTP/2.0 (0.1s) 200 response from GET https://music.provider.plex.tv
May 14, 2022 06:47:50.481 [0x7f871e3afb38] WARN - [MediaProviderManager] Unrecognized MediaProvider feature: availability
May 14, 2022 06:47:50.481 [0x7f871e3afb38] WARN - [MediaProviderManager] Unrecognized MediaProvider feature: availability-platforms
May 14, 2022 06:47:50.481 [0x7f871e3afb38] DEBUG - [MediaProviderManager] loading cloud provider details (Music) (alive: 1)
May 14, 2022 06:47:50.481 [0x7f871e3afb38] DEBUG - [MediaProviderManager] loading cloud provider details (Movies & TV) (alive: 1)
May 14, 2022 06:47:50.481 [0x7f871e3afb38] DEBUG - [MediaProviderManager] we had 0 cloud providers online, we now have 3
May 14, 2022 06:47:50.481 [0x7f871e3afb38] DEBUG - [MediaProviderManager] cloud provider (Metadata) is online and available
May 14, 2022 06:47:50.481 [0x7f871e3afb38] DEBUG - [MediaProviderManager] cloud provider (Music) is online and available
May 14, 2022 06:47:50.481 [0x7f871e3afb38] DEBUG - [MediaProviderManager] cloud provider (Movies & TV) is online and available
May 14, 2022 06:47:50.481 [0x7f871e3afb38] DEBUG - [MediaProviderManager] HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:50.500 [0x7f871e1afb38] WARN - [MediaProviderManager] Unrecognized MediaProvider feature: availability
May 14, 2022 06:47:50.500 [0x7f871e1afb38] WARN - [MediaProviderManager] Unrecognized MediaProvider feature: availability-platforms
May 14, 2022 06:47:50.656 [0x7f871e37bb38] DEBUG - [HttpClient] HTTP/2.0 (0.2s) 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx (reused)
May 14, 2022 06:47:50.656 [0x7f871e3afb38] DEBUG - [MediaProviderManager] discovered cloud provider (Movies & TV)
May 14, 2022 06:47:50.656 [0x7f871e3afb38] DEBUG - [MediaProviderManager] discovered cloud provider (Music)
May 14, 2022 06:47:50.656 [0x7f871e3afb38] DEBUG - [MediaProviderManager] discovered cloud provider (Metadata)
May 14, 2022 06:47:50.656 [0x7f871e3afb38] DEBUG - [MediaProviderManager] loading cloud provider details (Metadata) (alive: 1)
May 14, 2022 06:47:50.656 [0x7f871e3afb38] DEBUG - [MediaProviderManager] loading cloud provider details (Music) (alive: 1)
May 14, 2022 06:47:50.656 [0x7f871e3afb38] DEBUG - [MediaProviderManager] loading cloud provider details (Movies & TV) (alive: 1)
May 14, 2022 06:47:50.656 [0x7f871e3afb38] DEBUG - [MediaProviderManager] we had 3 cloud providers online, we now have 3
May 14, 2022 06:47:50.656 [0x7f871e3afb38] DEBUG - [MediaProviderManager] cloud provider (Metadata) is online and available
May 14, 2022 06:47:50.656 [0x7f871e3afb38] DEBUG - [MediaProviderManager] cloud provider (Music) is online and available
May 14, 2022 06:47:50.656 [0x7f871e3afb38] DEBUG - [MediaProviderManager] cloud provider (Movies & TV) is online and available
May 14, 2022 06:47:50.725 [0x7f871e02eb38] DEBUG - Reading 486 bytes in the body, code is 200
May 14, 2022 06:47:50.725 [0x7f871e02eb38] DEBUG - [com.plexapp.system] Plug-in running on port 34879.
May 14, 2022 06:47:50.725 [0x7f871e02eb38] DEBUG -  * Plug-in handles prefix: /system
May 14, 2022 06:47:50.725 [0x7f871e02eb38] DEBUG -  * Plug-in handles prefix: /player
May 14, 2022 06:47:50.725 [0x7f871e02eb38] DEBUG - Read configuration for [com.plexapp.system], had 2 prefixes
May 14, 2022 06:47:50.725 [0x7f871e02eb38] DEBUG - Done with 1 synchronous plug-in starts, starting the rest in parallel.
May 14, 2022 06:47:50.725 [0x7f871e02eb38] DEBUG - PluginRepository::setStartState: 2, startingPlugins
May 14, 2022 06:47:50.725 [0x7f871e02eb38] DEBUG - Updating the list of agents known by the system.
May 14, 2022 06:47:50.725 [0x7f871e02eb38] DEBUG - [com.plexapp.system] Sending command over HTTP (GET): /system/agents
May 14, 2022 06:47:50.725 [0x7f871e02eb38] DEBUG - HTTP requesting GET http://127.0.0.1:34879/system/agents
May 14, 2022 06:47:50.726 [0x7f87207ded48] DEBUG - Image transcode cache directory: "/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/PhotoTranscoder"
May 14, 2022 06:47:50.729 [0x7f87207ded48] DEBUG - Transcoder: Cleaning old transcode directories.
May 14, 2022 06:47:50.729 [0x7f87207ded48] DEBUG - MyPlex: using cached data for request for https://plex.tv/api/v2/server/access_tokens?auth_token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:50.730 [0x7f87207ded48] DEBUG - MyPlex: updating with 52 access tokens
May 14, 2022 06:47:50.735 [0x7f871e169b38] DEBUG - [MediaProviderManager] HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:50.735 [0x7f87207ded48] DEBUG - MyPlex: using cached data for request for https://plex.tv/api/v2/server/users?auth_token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:50.736 [0x7f87207ded48] DEBUG - MyPlex: using cached data for request for https://plex.tv/api/v2/server/users/subscriptions?auth_token=xxxxxxxxxxxxxxxxxxxx
May 14, 2022 06:47:50.737 [0x7f87207ded48] DEBUG - MyPlex: using cached data for request for https://plex.tv/api/v2/user?includeSubscriptions=1&includeProviders=1
May 14, 2022 06:47:50.738 [0x7f87207ded48] DEBUG - MyPlex: username is LightForce77, login is rick@alphadigital.net, home is 1, has pin
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - MyPlex: start public ip check and mapping - current mapped state: 'Unknown'.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - MyPlex: mapping state set to 'Not Mapped'.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - PublicAddressManager: Starting.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - PublicAddressManager: Obtaining public address and mapping port.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkInterface: Starting watch thread.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - Network change.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkInterface: Notified of network changed (force=0)
May 14, 2022 06:47:50.739 [0x7f871d99cb38] DEBUG - NetworkInterface: Watching for changes on the interfaces.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - Detected primary interface: 192.168.1.206
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - Network interfaces:
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG -  * 1 lo (127.0.0.1) (00-00-00-00-00-00) (loopback: 1)
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG -  * 2 eno1 (192.168.1.206) (3C-52-82-60-CA-BB) (loopback: 0)
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG -  * 1 lo (::1) (00-00-00-00-00-00) (loopback: 1)
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - Creating NetworkServices singleton.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkServices: Initializing...
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Creating new service.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Got notification of changed network (first change: 1)
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Quick dispatch of network change.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Creating new service.
May 14, 2022 06:47:50.739 [0x7f871d979b38] DEBUG - Network change for advertiser.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Got notification of changed network (first change: 1)
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Quick dispatch of network change.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Creating new service.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Got notification of changed network (first change: 1)
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Quick dispatch of network change.
May 14, 2022 06:47:50.739 [0x7f871d979b38] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:32414
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Creating new service.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Got notification of changed network (first change: 1)
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Quick dispatch of network change.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Creating new service.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Got notification of changed network (first change: 1)
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Quick dispatch of network change.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Creating new service.
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Got notification of changed network (first change: 1)
May 14, 2022 06:47:50.739 [0x7f87207ded48] DEBUG - NetworkService: Quick dispatch of network change.
May 14, 2022 06:47:50.740 [0x7f871d9e2b38] DEBUG - HTTP requesting GET https://plex.tv/api/v2/user?includeSubscriptions=1&includeProviders=1
May 14, 2022 06:47:50.741 [0x7f87207ded48] DEBUG - Starting HTTP server.
May 14, 2022 06:47:50.741 [0x7f871d956b38] DEBUG - [ChildProcessMonitor] Plex Tuner Service starting.
May 14, 2022 06:47:50.741 [0x7f87207ded48] DEBUG - Running server...
May 14, 2022 06:47:50.741 [0x7f87207ded48] DEBUG - Waiting for server condition to be signaled.
May 14, 2022 06:47:50.741 [0x7f871d956b38] DEBUG - [ChildProcessMonitor/JobRunner] Job running: "/usr/lib/plexmediaserver/Plex Tuner Service" /usr/lib/plexmediaserver/Resources/Tuner/Private /usr/lib/plexmediaserver/Resources/Tuner/Shared 1.26.0.5715-8cf78dab3 32600
May 14, 2022 06:47:50.741 [0x7f871d91db38] DEBUG - HttpServer: Set up a thread pool with 2 threads.
May 14, 2022 06:47:50.741 [0x7f871d979b38] DEBUG - Network change for advertiser.
May 14, 2022 06:47:50.741 [0x7f871d979b38] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:32410
May 14, 2022 06:47:50.742 [0x7f871d979b38] DEBUG - Network change for advertiser.

Moderator Edited: Legibility

2

Debugging this snippet doesn’t provide anything useful.

Would it be possible to have the entire ZIP file where you’ve recreated the failure to play media ?

3

what chuck said, can we get a copy of your server logs?

4

I wasn’t aware that I could include a file… The logs were archived, and the new ones were attached. I attempted to play a TV Show before I downloaded the logs.

Thank you!

Plex Media Server Logs_2022-05-15_06-38-48.zip (590.5 KB)

5

…I wanted to add that I do have some remote storage offline right now. However, non of the content that I have tried to view was on the remote storage. Everything was local to the PlexServer and accessible from the server.

6

This looks like the errors blocking your playback – Media isn’t available.

May 15, 2022 06:38:27.434 [0x7f5a9f5c0b38] DEBUG - Completed: [127.0.0.1:43164] 200 GET /channels/all (30 live) GZIP 0ms 387 bytes
May 15, 2022 06:38:29.195 [0x7f5a9f0b2b38] ERROR - IsDirectory failed boost::filesystem::status: Host is down: "/PlexMedia5.1/Documentaries"
May 15, 2022 06:38:29.195 [0x7f5a9f5f3b38] ERROR - Couldn't check for the existence of file "/PlexMedia5.1/Movies/_Inspirational/.grab": boost::filesystem::status: Host is down: "/PlexMedia5.1/Movies/_Inspirational/.grab"
May 15, 2022 06:38:29.195 [0x7f5a9f11bb38] ERROR - Couldn't check for the existence of file "/PlexMedia5/Documentries/.grab": boost::filesystem::status: Host is down: "/PlexMedia5/Documentries/.grab"
May 15, 2022 06:38:37.061 [0x7f5a9d7cab38] DEBUG - BPQ: onConsiderProcessing: Idle (true)
May 15, 2022 06:38:37.061 [0x7f5a9d7cab38] DEBUG - BPQ: [Idle] -> [Processing]
May 15, 2022 06:38:37.066 [0x7f5a9d7cab38] DEBUG - BPQ: generating queue items from 0 generator(s)
May 15, 2022 06:38:37.066 [0x7f5a9d7cab38] DEBUG - BPQ: generated 0 item(s) for queue
May 15, 2022 06:38:37.067 [0x7f5a9d7cab38] DEBUG - PlayQueue: 0 generated IDs compressed down to a 20 byte blob.
May 15, 2022 06:38:37.067 [0x7f5a9d7cab38] DEBUG - PlayQueue: 0 generated IDs compressed down to a 20 byte blob.
May 15, 2022 06:38:37.067 [0x7f5a9d7cab38] DEBUG - BPQ: [Processing] -> [Idle]
May 15, 2022 06:38:39.435 [0x7f5a9f11bb38] ERROR - Couldn't check for the existence of file "/PlexMedia4/Documentaries/.grab": boost::filesystem::status: Host is down: "/PlexMedia4/Documentaries/.grab"
May 15, 2022 06:38:39.435 [0x7f5a9f0b2b38] ERROR - IsDirectory failed boost::filesystem::status: Host is down: "/PlexMedia5.1/Ended-TV"
May 15, 2022 06:38:39.435 [0x7f5a9f5f3b38] ERROR - Couldn't check for the existence of file "/PlexMedia5.2/Movies/_Inspirational/.grab": boost::filesystem::status: Host is down: "/PlexMedia5.2/Movies/_Inspirational/.grab"
May 15, 2022 06:38:45.696 [0x7f5a9d7a7b38] DEBUG - Request: [192.168.1.13:39778 (Subnet)] GET /accounts/1 (32 live) TLS GZIP Signed-in Token (LightForce77) (Chrome)

I see it use the known XML to decide what to do then it stops with these errors.

May 15, 2022 06:37:28.156 [0x7f5a9f236b38] DEBUG - Audio Stream: 528950, Subtitle Stream: -1
May 15, 2022 06:37:28.157 [0x7f5a9f236b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
May 15, 2022 06:37:28.157 [0x7f5a9f236b38] DEBUG - Selecting best audio stream for part ID 189965 (autoselect: 1 language: en)
May 15, 2022 06:37:28.157 [0x7f5a9f236b38] DEBUG - We're going to try to auto-select a subtitle.
May 15, 2022 06:37:28.157 [0x7f5a9f236b38] DEBUG - Audio Stream: 528585, Subtitle Stream: -1
May 15, 2022 06:37:28.157 [0x7f5a9f236b38] DEBUG - We're going to try to auto-select an audio stream for account 1.
May 15, 2022 06:37:28.157 [0x7f5a9f236b38] DEBUG - Selecting best audio stream for part ID 216416 (autoselect: 1 language: en)
May 15, 2022 06:37:28.157 [0x7f5a9f236b38] DEBUG - We're going to try to auto-select a subtitle.
May 15, 2022 06:37:28.157 [0x7f5a9f236b38] DEBUG - Audio Stream: 611897, Subtitle Stream: -1
May 15, 2022 06:37:28.160 [0x7f5a9f59db38] DEBUG - Completed: [192.168.1.13:39562] 200 GET /hubs/continueWatching/items?contentDirectoryID=3%2C13%2C10%2C1%2C4%2C6%2C7%2C5 (12 live) TLS GZIP 193ms 24032 bytes (pipelined: 6)
May 15, 2022 06:37:28.779 [0x7f5a9f11bb38] ERROR - Couldn't check for the existence of file "/PlexMedia5/Misic/.grab": boost::filesystem::status: Host is down: "/PlexMedia5/Misic/.grab"
May 15, 2022 06:37:29.035 [0x7f5a9f0b2b38] ERROR - IsDirectory failed boost::filesystem::status: Host is down: "/PlexMedia5/Movies/_Inspirational"
May 15, 2022 06:37:37.059 [0x7f5a9f236b38] DEBUG - Request: [192.168.1.13:39562 (Subnet)] POST /playQueues?type=video&continuous=1&uri=server%3A%2F%2F29c9d954bf02d58393ea84ae16b0ef0020c66be0%2Fcom.plexapp.plugins.library%2Flibrary%2Fmetadata%2F91234&repeat=0&own=1&includeChapters=1&includeMarkers=1&includeGeolocation=1&includeExternalMedia=1 (12 live) TLS GZIP Signed-in Token (LightForce77) (Chrome)
7

That’s odd that of some if the shares are down, it would effect all playback. I do have a storage server doe, but none of the local media will play. All of errors point to the unavailable storage.

8

Can you try to play some local media, upload the logs, and provide the filename and path you were trying to play?

9

Those were the only named playback attempts I found in the logs.

If you can try to play a file, capture the logs again after the failure, and share the file name, we’ll go through the logs again.

10

Actually, we had a power outage and when everythnjg back up, Plex was working again I rebooted and powered down the server several times, but had no success. My guess is that he issue was related to my router.

Thanks for looking into this.

11

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