Media Server Stuck in Starting After Update

Server Version#:1.14.0.5470-9d51fdfaa
Player Version#:N/A

My PMS on macOS 10.14.1 was set to update last night. This morning it is stuck saying “Server is starting…” in the menu bar.

I have tried downloading a fresh copy from the Plex site and installing it, I have restarted PMS a few times, and also rebooted my computer.

I’m seeing the following errors in the Plex Media Center.1.log, if it helps

Dec 01, 2018 06:08:46.483 [0x70000e7a8000] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 01, 2018 06:08:46.483 [0x70000e7a8000] WARN - HTTP error requesting POST http://127.0.0.1:32600/devices/discover (0, No error) (Failed connect to 127.0.0.1:32600; Connection refused)
Dec 01, 2018 06:11:36.482 [0x70000e8ae000] ERROR - Timeout or error reading status line from plug-in pipe [com.plexapp.system], we're killing it.
Dec 01, 2018 06:11:36.483 [0x70000e8ae000] ERROR - Error received reading configuration for com.plexapp.system
Dec 01, 2018 06:11:38.503 [0x70000e101000] ERROR - Network Service: Error in browser handle read: 89 (Operation canceled) socket=-1
Dec 01, 2018 06:12:33.498 [0x70000e8ae000] ERROR - Timeout or error reading status line from plug-in pipe [com.plexapp.system], we're killing it.
Dec 01, 2018 06:12:33.498 [0x70000e8ae000] ERROR - Error received reading configuration for com.plexapp.system

Update…

I realized I was looking at the wrong log. This is what the Plex Media Server.log shows upon fresh start up.

Dec 01, 2018 11:26:49.134 [0x7000072ea000] ERROR - Error issuing curl_easy_perform(handle): 7
Dec 01, 2018 11:26:49.134 [0x7000072ea000] WARN - HTTP error requesting POST http://127.0.0.1:32600/devices/discover (0, No error) (Failed connect to 127.0.0.1:32600; Connection refused)
Dec 01, 2018 11:29:38.635 [0x700007702000] ERROR - Timeout or error reading status line from plug-in pipe [com.plexapp.system], we're killing it.
Dec 01, 2018 11:29:38.635 [0x700007702000] ERROR - Error received reading configuration for com.plexapp.system
Dec 01, 2018 11:29:39.768 [0x70000736d000] DEBUG - NotificationStream: Removing because of error

Dec 01, 2018 11:29:40.973 [0x700006f55000] ERROR - Network Service: Error in browser handle read: 89 (Operation canceled) socket=-1

After it timed out, I was able to get to the web client on the local host, my content is there and I can watch videos locally. It appears media it now showing in the AppleTV client as well.

However, my server setting are unavailable, and the menubar dropdown is still stuck on “Server is starting…”

After a few minutes and bringing up the dashboard on the AppleTV, the be low was added to the log.

Dec 01, 2018 11:31:18.279 [0x7000070de000] ERROR - QueryParser: Invalid field '&onlyTransient' found, ignoring.
Dec 01, 2018 11:31:19.564 [0x7000070de000] ERROR - Error issuing curl_easy_perform(handle): 3
Dec 01, 2018 11:31:19.564 [0x7000070de000] WARN - HTTP error requesting GET  (0, No error) (<url> malformed)

Dec 01, 2018 11:31:33.357 [0x7000073f0000] DEBUG - NotificationStream: Removing because of error

Dec 01, 2018 11:31:40.302 [0x7000070de000] ERROR - Error issuing curl_easy_perform(handle): 3
Dec 01, 2018 11:31:40.302 [0x7000070de000] WARN - HTTP error requesting GET  (0, No error) (<url> malformed)

Dec 01, 2018 11:32:38.634 [0x700007702000] ERROR - Timeout or error reading status line from plug-in pipe [com.plexapp.system], we're killing it.
Dec 01, 2018 11:32:38.634 [0x700007702000] ERROR - Error received reading configuration for com.plexapp.system

Can anyone help me out here? I’ve tried upgrading to Version 1.14.1.5488-cc260c476 and am experiencing the same behavior of the server stuck in “starting” and all settings being unavailable.

If there is any information I can supply to help get to a resolution I will be more than happy to provide it.

Have you updated to 10.14.2, I’m running the latest PMS without issue.

Try launching PMS from the Browser directly.

https://app.plex.tv/desktop#

The latest version I see is the one I mentioned I upgraded to. It’s PMS (the server) that I’m having the issue with.

The browser client will launch, but because the server never fully launches, I’m unable to have my new media scanned, and assume I’ll have a host of other issues… not to mention settings being unavailable if any changes need to be made at some point down the road. I also have my library set for manual scanning, so since the server never fully starts, the update library option is grayed out, so I can’t scan for new material… but the last 10 or so things I added just have screenshots of the video, they weren’t able to get the art and other metadata from the web.

You mentioned 10.14.1 not 10.14.2, please note this fixed this issue with another member

Where can I get this new version? When I look at the available downloads I’m on the latest version.

That’s MacOS you update from the system preferences pane

Ah, thanks for the clarification. With both being at x.14.1… I missed that distinction.

I updated to 10.14.2, but am experiencing the same issues.

I just tried the following without any luck:

  • Stopped Server
  • Created new, empty ~/Library/Applicatin Support/Plex Media Server folder and started the server. No change. Stopped Server.
  • Put old folder back
  • Removed plex plist file and started server. No change. Stopped server.
  • Put old plist back
  • Removed ~/Library/Caches/Plex Media Server and started server. No change. Stopped server.
  • Put old Caches folder back
  • Re-downloaded Plex again (with the non-Plex Pass option this time). No change.

Current PMS Version: 1.14.1.5488-cc260c476
Current OS Version: MacOS 10.14.2 (18C54)

What else can I do here?

It sticks like this, never fully starting…

All server setting just give me this…

New content can’t be loaded in. Movie posters and info seems to be disappearing more and more.

Here is the log up until the WebUI will actually come up.

Jan 12, 2019 14:10:08.055 [0x7000034d0000] INFO - Plex Media Server v1.14.1.5488-cc260c476 - Apple Mac x86_64 - build: darwin-x86_64 macosx - GMT -06:00
Jan 12, 2019 14:10:08.055 [0x7000034d0000] INFO - MacOSX version: 10.14.2, language: en-US
Jan 12, 2019 14:10:08.055 [0x7000034d0000] INFO - Processor Intel(R) Core(TM) i5-8500B CPU @ 3.00GHz
Jan 12, 2019 14:10:08.055 [0x7000034d0000] INFO - /Applications/Plex Media Server.app/Contents/MacOS/Plex Media Server -psn_0_8050605
Jan 12, 2019 14:10:08.185 [0x7000037e2000] DEBUG - BPQ: [Idle] -> [Starting]
Jan 12, 2019 14:10:08.188 [0x7000037e2000] DEBUG - FeatureManager: Using cached data for features list
Jan 12, 2019 14:10:08.190 [0x7000037e2000] DEBUG - Opening 20 database sessions to library (com.plexapp.plugins.library), SQLite 3.13.0, threadsafe=1
Jan 12, 2019 14:10:08.755 [0x7000037e2000] DEBUG - Running migrations. (EPG 0)
Jan 12, 2019 14:10:08.947 [0x7000037e2000] DEBUG - ChangestampAllocator: initialized to 1119021
Jan 12, 2019 14:10:08.947 [0x7000037e2000] DEBUG - Opening 2 database sessions to library (com.plexapp.plugins.library.blobs), SQLite 3.13.0, threadsafe=1
Jan 12, 2019 14:10:09.040 [0x7000037e2000] DEBUG - Running migrations. (EPG 0)
Jan 12, 2019 14:10:09.049 [0x7000037e2000] DEBUG - CERT: Installed certificate with fingerprint 05:60:54:36:62:26:4a:20:5f:39:d4:4c:20:4e:64:d8:9b:00:97:1a.
Jan 12, 2019 14:10:09.049 [0x7000037e2000] DEBUG - CERT: Installed new private key.
Jan 12, 2019 14:10:09.049 [0x7000037e2000] DEBUG - CERT: Subject name is /C=US/ST=California/L=Los Gatos/O=Plex, Inc./CN=*.994db416a1cf43288b3d258fb4d1eb97.plex.direct
Jan 12, 2019 14:10:09.050 [0x7000037e2000] DEBUG - CERT: OCSP requests for stapling will be made to 'http://ocspx.digicert.com/'.
Jan 12, 2019 14:10:09.050 [0x7000037e2000] INFO - OCSP: Successfully retrieved response from cache.
Jan 12, 2019 14:10:09.050 [0x7000037e2000] DEBUG - CERT: Installed intermediate certificate.
Jan 12, 2019 14:10:09.051 [0x7000037e2000] DEBUG - HttpServer: Listening on port 32400 with queue of 128 connections.
Jan 12, 2019 14:10:09.051 [0x7000037e2000] DEBUG - HttpServer: Listening on port 32401 with queue of 128 connections.
Jan 12, 2019 14:10:09.063 [0x700003a71000] DEBUG - DVR:Grabber: Cleaning up orphaned grabs.
Jan 12, 2019 14:10:09.063 [0x7000037e2000] DEBUG - Media Provider: Registering provider com.plexapp.plugins.library
Jan 12, 2019 14:10:09.064 [0x7000037e2000] DEBUG - Auth: Refreshing tokens inside the token-based authentication filter.
Jan 12, 2019 14:10:09.064 [0x700003af4000] DEBUG - Relay: read 1 cached entries from hosts file
Jan 12, 2019 14:10:09.064 [0x700003a71000] DEBUG - DVR:Grabber: Cleaned up 0 decrepit directories in 0.0 sec.
Jan 12, 2019 14:10:09.064 [0x7000037e2000] DEBUG - MyPlex: using cached data for request for https://plex.tv/servers/963bb2d1ba1aca247d773d45241db2245c418895/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Jan 12, 2019 14:10:09.065 [0x700003af4000] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Jan 12, 2019 14:10:09.065 [0x7000037e2000] DEBUG - MyPlex: updating with 7 access tokens
Jan 12, 2019 14:10:09.065 [0x700003bfa000] DEBUG - Auth: Refreshing tokens inside the token-based authentication filter.
Jan 12, 2019 14:10:09.065 [0x700003bfa000] DEBUG - HTTP requesting GET https://plex.tv/servers/963bb2d1ba1aca247d773d45241db2245c418895/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Jan 12, 2019 14:10:09.066 [0x700003d00000] DEBUG - File "/Applications/Plex Media Server.app/Contents/Resources/Plug-ins-cc260c476" changed: -1 => 2018-12-14 10:52:44 (1544806364).
Jan 12, 2019 14:10:09.066 [0x700003d00000] DEBUG - File "/Users/alan/Library/Application Support/Plex Media Server/Plug-ins" changed: -1 => 2018-11-11 12:56:00 (1541962560).
Jan 12, 2019 14:10:09.066 [0x700003d00000] DEBUG - Scanning for plug-ins in "/Applications/Plex Media Server.app/Contents/Resources/Plug-ins-cc260c476"
Jan 12, 2019 14:10:09.068 [0x700003d00000] DEBUG - Scanning for plug-ins in "/Users/alan/Library/Application Support/Plex Media Server/Plug-ins"
Jan 12, 2019 14:10:09.069 [0x700003d00000] DEBUG - PluginRepository::setStartState: 1, startingSystem
Jan 12, 2019 14:10:09.069 [0x700003d00000] DEBUG - Starting plug-in /Applications/Plex Media Server.app/Contents/Resources/Plug-ins-cc260c476/System.bundle.
Jan 12, 2019 14:10:09.069 [0x700003d00000] DEBUG - [com.plexapp.system] Setting plug-in to always running (daemon mode).
Jan 12, 2019 14:10:09.082 [0x700003d00000] DEBUG - Starting file watcher for com.plexapp.system
Jan 12, 2019 14:10:09.086 [0x700003d00000] DEBUG - Spawned plug-in com.plexapp.system with PID 11709
Jan 12, 2019 14:10:09.086 [0x700003d00000] DEBUG - [com.plexapp.system] Sending command: GET /:/prefixes
Jan 12, 2019 14:10:09.676 [0x700003af4000] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Jan 12, 2019 14:10:09.777 [0x700003bfa000] DEBUG - HTTP 200 response from GET https://plex.tv/servers/963bb2d1ba1aca247d773d45241db2245c418895/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Jan 12, 2019 14:10:09.777 [0x700003bfa000] DEBUG - MyPlex: updating with 7 access tokens
Jan 12, 2019 14:10:09.778 [0x700003a71000] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Jan 12, 2019 14:10:10.045 [0x7000038e8000] DEBUG - Job running: '/Applications/Plex Media Server.app/Contents/MacOS/CrashUploader' '--directory=/Users/alan/Library/Application Support/Plex Media Server/Crash Reports/1.14.1.5488-cc260c476' '--version=1.14.1.5488-cc260c476' '--platform=darwin-x86_64 (10.14.2)' '--serverUuid=963bb2d1ba1aca247d773d45241db2245c418895' '--userId=phormality+plexapp@gmail.com' '--url=https://crashreport.plexapp.com'
Jan 12, 2019 14:10:10.046 [0x7000038e8000] DEBUG - Jobs: Starting child process with pid 11710
Jan 12, 2019 14:10:10.079 [0x700003c7d000] DEBUG - Jobs: '/Applications/Plex Media Server.app/Contents/MacOS/CrashUploader' exit code for process 11710 is 0 (success)
Jan 12, 2019 14:10:10.361 [0x700003a71000] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Jan 12, 2019 14:10:10.361 [0x700003a71000] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Jan 12, 2019 14:10:11.000 [0x700003a71000] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Jan 12, 2019 14:10:11.001 [0x700003af4000] DEBUG - HTTP requesting GET https://music.provider.plex.tv?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Jan 12, 2019 14:10:11.001 [0x700003a71000] DEBUG - HTTP requesting GET https://music.provider.plex.tv?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Jan 12, 2019 14:10:11.194 [0x700003a71000] DEBUG - HTTP 200 response from GET https://music.provider.plex.tv?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Jan 12, 2019 14:10:11.198 [0x700003af4000] DEBUG - HTTP 200 response from GET https://music.provider.plex.tv?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Jan 12, 2019 14:10:18.612 [0x1133835c0] DEBUG - Image transcode cache directory: "/Users/alan/Library/Caches/PlexMediaServer/PhotoTranscoder"
Jan 12, 2019 14:10:19.068 [0x700003bfa000] DEBUG - DVR:Device: Discovering and refreshing all devices.
Jan 12, 2019 14:10:19.069 [0x700003bfa000] DEBUG - Creating NetworkServices singleton.
Jan 12, 2019 14:10:19.069 [0x700003bfa000] DEBUG - NetworkService: Creating new service.
Jan 12, 2019 14:10:19.069 [0x700003bfa000] DEBUG - NetworkService: Got notification of changed network (first change: 1)
Jan 12, 2019 14:10:19.069 [0x700003bfa000] DEBUG - NetworkService: Quick dispatch of network change.
Jan 12, 2019 14:10:19.069 [0x700003bfa000] DEBUG - DVR:Grabber: HDHomerun discovered 0 compatible devices.
Jan 12, 2019 14:10:19.069 [0x700003e89000] DEBUG - NetworkService: Network change for browser (polled=0), closing 0 browse sockets.
Jan 12, 2019 14:10:19.069 [0x700003e89000] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:1901 (outbound: 0)
Jan 12, 2019 14:10:19.070 [0x700003bfa000] DEBUG - HTTP requesting POST http://127.0.0.1:32600/devices/discover
Jan 12, 2019 14:10:19.070 [0x700003bfa000] ERROR - Error issuing curl_easy_perform(handle): 7
Jan 12, 2019 14:10:19.070 [0x700003bfa000] WARN - HTTP error requesting POST http://127.0.0.1:32600/devices/discover (0, No error) (Failed connect to 127.0.0.1:32600; Connection refused)
Jan 12, 2019 14:10:19.070 [0x700003bfa000] DEBUG - DVR:Grabber: Failed to retrieve device data
Jan 12, 2019 14:12:08.191 [0x7000035d6000] DEBUG - BPQ: [Starting] -> [Processing]
Jan 12, 2019 14:12:08.542 [0x7000035d6000] DEBUG - BPQ: generating queue items from 0 generator(s)
Jan 12, 2019 14:12:08.542 [0x7000035d6000] DEBUG - BPQ: generated 0 item(s) for queue
Jan 12, 2019 14:12:08.543 [0x7000035d6000] DEBUG - PlayQueue: 0 generated IDs compressed down to a 2 byte blob.
Jan 12, 2019 14:12:08.543 [0x7000035d6000] DEBUG - PlayQueue: 0 generated IDs compressed down to a 2 byte blob.
Jan 12, 2019 14:12:08.627 [0x7000035d6000] DEBUG - BPQ: [Processing] -> [Idle]
Jan 12, 2019 14:13:09.084 [0x700003d00000] ERROR - Timeout or error reading status line from plug-in pipe [com.plexapp.system], we're killing it.
Jan 12, 2019 14:13:09.084 [0x700003d00000] DEBUG - Stopping [com.plexapp.system].
Jan 12, 2019 14:13:09.084 [0x700003d00000] DEBUG - [com.plexapp.system] Killing.
Jan 12, 2019 14:13:09.084 [0x700003d00000] ERROR - Error received reading configuration for com.plexapp.system
Jan 12, 2019 14:13:09.084 [0x700003d00000] DEBUG - Stopping [com.plexapp.system].
Jan 12, 2019 14:13:09.084 [0x700003d00000] DEBUG - Done with 1 synchronous plug-in starts, starting the rest in parallel.
Jan 12, 2019 14:13:09.084 [0x700003d00000] DEBUG - PluginRepository::setStartState: 2, startingPlugins
Jan 12, 2019 14:13:09.084 [0x700003d00000] DEBUG - Updating the list of agents known by the system.
Jan 12, 2019 14:13:09.084 [0x700003d00000] DEBUG - Starting file watcher for com.plexapp.system
Jan 12, 2019 14:13:09.088 [0x700003d00000] DEBUG - Spawned plug-in com.plexapp.system with PID 11723
Jan 12, 2019 14:13:09.088 [0x700003d00000] DEBUG - [com.plexapp.system] Sending command: GET /:/prefixes
Jan 12, 2019 14:13:09.088 [0x7000037e2000] WARN - SLOW QUERY: It took 730.000000 ms to retrieve 0 items.
Jan 12, 2019 14:13:09.089 [0x7000037e2000] WARN - Held transaction for too long (../Plugins/PluginDatabaseState.cpp:51): 0.730000 seconds

I removed Plex completely. Rebooted. Installed it again, and relaunched… still not working. I’ve attached the logs here.

Plex Media (34.4 KB)

Here is what shows in the WebUI now on the fresh install.

SOVLED

To get a lot of the metadata off my primary drive I was using a symlink, which had worked fine for many month, and I saw a lot of people using it without issue online. I removed that and migrated the Application Support data back to my primary drive. This got Plex to start.

Once it started, my libraries were not loading properly. I re-scanned and optimized the database, quit and restarted Plex, and it started working.

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