Server Version#: 1.16.5.1554
Player Version#:
Since upgrading to latest version, server will not start. Logs show read-only error on database access. Permissions seem OK; trying to do database recovery using sqlite3 results in same error.
Sep 13, 2019 10:47:01.748 [3816] INFO - Plex Media Server v1.16.5.1554-1e5ff713d - Microsoft PC x64 - build: windows-x86 windows - GMT 10:00
Sep 13, 2019 10:47:01.748 [3816] INFO - Windows version: 10.0 (Build 14393), language en-US
Sep 13, 2019 10:47:01.748 [3816] INFO - 4 3392 MHz processor(s): Architecture=0, Level=6, Revision=15363 Processor Identifier=Intel64 Family 6 Model 60 Stepping 3, GenuineIntel
Sep 13, 2019 10:47:01.748 [3816] DEBUG - “C:\Program Files (x86)\Plex\Plex Media Server\Plex Media Server.exe”
Sep 13, 2019 10:47:01.748 [3780] DEBUG - Plex for Windows Store application is not installed
Sep 13, 2019 10:47:01.763 [3780] DEBUG - BPQ: [Idle] -> [Starting]
Sep 13, 2019 10:47:01.810 [3780] DEBUG - FeatureManager: Using cached data for features list
Sep 13, 2019 10:47:01.826 [3780] DEBUG - Opening 20 database sessions to library (com.plexapp.plugins.library), SQLite 3.26.0, threadsafe=1
Sep 13, 2019 10:47:02.483 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.535 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.548 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.564 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.579 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.595 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.611 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.626 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.642 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.657 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.673 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.689 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.704 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.720 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.735 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.752 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.767 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.767 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.782 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.782 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 692 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.db-wal
Sep 13, 2019 10:47:02.798 [3780] DEBUG - Running migrations. (EPG 0)
Sep 13, 2019 10:47:03.732 [3836] DEBUG - Job running: C:\Program Files (x86)\Plex\Plex Media Server\CrashUploader.exe “–directory=Q:\Arnie\Plex Media Server\Crash Reports\1.16.5.1554-1e5ff713d” --version=1.16.5.1554-1e5ff713d --platform=Windows “–platformVersion=10.0 (Build 14393)” --serverUuid=4fb3058f5a842f371666d3e6684e8a82bf6aeb83 --userId=lee@witsend.id.au --sentryUrl=https://sentry.io/api/1233455/minidump --sentryKey=xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx --vendor=Microsoft --model=x64 --device=PC
Sep 13, 2019 10:47:03.873 [3836] DEBUG - Jobs: Starting child process with pid 3840
Sep 13, 2019 10:47:04.173 [3892] DEBUG - Jobs: ‘C:\Program Files (x86)\Plex\Plex Media Server\CrashUploader.exe’ exit code for process 3840 is 0 (success)
Sep 13, 2019 10:47:04.975 [3780] DEBUG - ChangestampAllocator: initialized to 1166005
Sep 13, 2019 10:47:04.975 [3780] DEBUG - Opening 2 database sessions to library (com.plexapp.plugins.library.blobs), SQLite 3.26.0, threadsafe=1
Sep 13, 2019 10:47:05.147 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 359 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.blobs.db-wal
Sep 13, 2019 10:47:05.162 [3780] INFO - SQLITE3:0xc76f2bdc, 283, recovered 359 frames from WAL file Q:\Arnie\Plex Media Server\Plug-in Support\Databases\com.plexapp.plugins.library.blobs.db-wal
Sep 13, 2019 10:47:05.162 [3780] DEBUG - Running migrations. (EPG 0)
Sep 13, 2019 10:47:06.320 [3780] DEBUG - CERT: Installed certificate with fingerprint b2:a4:16:3c:2b:de:4f:13:c6:c5:3e:ce:85:8d:3a:96:35:fd:27:28.
Sep 13, 2019 10:47:06.320 [3780] DEBUG - CERT: Installed new private key.
Sep 13, 2019 10:47:06.320 [3780] DEBUG - CERT: Subject name is /C=US/ST=California/L=Los Gatos/O=Plex, Inc./CN=*.5bf2d00c47724d50acd5351bfb88d877.plex.direct
Sep 13, 2019 10:47:06.351 [3780] DEBUG - CERT: OCSP requests for stapling will be made to ‘http://ocspx.digicert.com/’.
Sep 13, 2019 10:47:06.382 [3780] INFO - OCSP: Successfully retrieved response from cache.
Sep 13, 2019 10:47:06.382 [3780] DEBUG - CERT: Installed intermediate certificate.
Sep 13, 2019 10:47:06.398 [3780] DEBUG - HttpServer: Listening on IPv6 as well as IPv4.
Sep 13, 2019 10:47:06.398 [3780] DEBUG - HttpServer: Listening on port 32400 with queue of 2147483647 connections.
Sep 13, 2019 10:47:06.398 [3780] DEBUG - HttpServer: Listening on port 32401 with queue of 2147483647 connections.
Sep 13, 2019 10:47:07.258 [3836] DEBUG - DVR:Grabber: Cleaning up orphaned grabs.
Sep 13, 2019 10:47:07.258 [3780] DEBUG - Media Provider: Registering provider com.plexapp.plugins.library
Sep 13, 2019 10:47:07.258 [3780] DEBUG - Auth: Refreshing tokens inside the token-based authentication filter.
Sep 13, 2019 10:47:07.289 [3916] DEBUG - Relay: read 21 cached entries from hosts file
Sep 13, 2019 10:47:07.289 [3916] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 13, 2019 10:47:07.289 [3780] DEBUG - MyPlex: using cached data for request for https://plex.tv/servers/4fb3058f5a842f371666d3e6684e8a82bf6aeb83/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Sep 13, 2019 10:47:07.305 [3780] DEBUG - MyPlex: updating with 9 access tokens
Sep 13, 2019 10:47:07.305 [3780] DEBUG - Opening 1 database sessions to library (), SQLite 3.26.0, threadsafe=1
Sep 13, 2019 10:47:07.305 [3928] DEBUG - Auth: Refreshing tokens inside the token-based authentication filter.
Sep 13, 2019 10:47:07.305 [3932] DEBUG - File “C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-1e5ff713d” changed: -1 => 2019-09-13 10:31:47 (1568334707).
Sep 13, 2019 10:47:07.320 [3928] DEBUG - HTTP requesting GET https://plex.tv/servers/4fb3058f5a842f371666d3e6684e8a82bf6aeb83/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Sep 13, 2019 10:47:07.320 [3932] DEBUG - File “Q:\Arnie\Plex Media Server\Plug-ins” changed: -1 => 2018-12-15 21:37:43 (1544870263).
Sep 13, 2019 10:47:07.320 [3932] DEBUG - Scanning for plug-ins in “C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-1e5ff713d”
Sep 13, 2019 10:47:07.367 [3836] DEBUG - DVR:Grabber: Cleaned up 0 decrepit directories in 0.1 sec.
Sep 13, 2019 10:47:07.633 [3932] DEBUG - Scanning for plug-ins in “Q:\Arnie\Plex Media Server\Plug-ins”
Sep 13, 2019 10:47:07.993 [3932] DEBUG - PluginRepository::setStartState: 1, startingSystem
Sep 13, 2019 10:47:07.993 [3932] DEBUG - Starting plug-in C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-1e5ff713d\System.bundle.
Sep 13, 2019 10:47:07.993 [3932] DEBUG - [com.plexapp.system] Setting plug-in to always running (daemon mode).
Sep 13, 2019 10:47:08.024 [3932] DEBUG - Starting file watcher for com.plexapp.system
Sep 13, 2019 10:47:08.025 [3932] DEBUG - Plugin::createProcess: Creating plugin process: “C:\Program Files (x86)\Plex\Plex Media Server\PlexScriptHost.exe” “C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-1e5ff713d\Framework.bundle\Contents\Resources\Versions\2\Python\bootstrap.py” “C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-1e5ff713d\System.bundle”
Sep 13, 2019 10:47:08.025 [3932] DEBUG - Spawned plug-in com.plexapp.system with PID 3956
Sep 13, 2019 10:47:08.025 [3932] DEBUG - [com.plexapp.system] Sending command: GET /:/prefixes
Sep 13, 2019 10:47:08.550 [3916] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 13, 2019 10:47:08.628 [3928] DEBUG - HTTP 200 response from GET https://plex.tv/servers/4fb3058f5a842f371666d3e6684e8a82bf6aeb83/access_tokens.xml?auth_token=xxxxxxxxxxxxxxxxxxxx&includeProfiles=1&includeProviders=1
Sep 13, 2019 10:47:08.644 [3928] DEBUG - MyPlex: updating with 9 access tokens
Sep 13, 2019 10:47:08.644 [3900] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 13, 2019 10:47:09.848 [3900] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 13, 2019 10:47:09.848 [3900] DEBUG - HTTP requesting GET https://music.provider.plex.tv?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 13, 2019 10:47:09.848 [3836] DEBUG - HTTP requesting GET https://music.provider.plex.tv?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 13, 2019 10:47:11.146 [3900] DEBUG - HTTP 200 response from GET https://music.provider.plex.tv?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 13, 2019 10:47:11.146 [3836] DEBUG - HTTP 200 response from GET https://music.provider.plex.tv?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 13, 2019 10:47:11.146 [3900] DEBUG - HTTP requesting GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 13, 2019 10:47:12.365 [3900] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 13, 2019 10:47:17.262 [3836] DEBUG - DVR:Device: Discovering and refreshing all devices.
Sep 13, 2019 10:47:17.262 [3836] DEBUG - Creating NetworkServices singleton.
Sep 13, 2019 10:47:17.262 [3836] DEBUG - NetworkService: Creating new service.
Sep 13, 2019 10:47:17.262 [3836] DEBUG - NetworkService: Got notification of changed network (first change: 1)
Sep 13, 2019 10:47:17.262 [3836] DEBUG - NetworkService: Quick dispatch of network change.
Sep 13, 2019 10:47:17.262 [3216] DEBUG - NetworkService: Network change for browser (polled=0), closing 0 browse sockets.
Sep 13, 2019 10:47:17.262 [3836] DEBUG - DVR:Grabber: HDHomerun discovered 0 compatible devices.
Sep 13, 2019 10:47:17.262 [3216] DEBUG - NetworkService: Setting up multicast listener on 0.0.0.0:1901
Sep 13, 2019 10:47:17.262 [3836] DEBUG - HTTP requesting POST http://127.0.0.1:32600/devices/discover
Sep 13, 2019 10:47:18.469 [3836] ERROR - Error issuing curl_easy_perform(handle): 7
Sep 13, 2019 10:47:18.469 [3836] WARN - HTTP error requesting POST http://127.0.0.1:32600/devices/discover (0, No error) (Failed to connect to 127.0.0.1 port 32600: Connection refused)
Sep 13, 2019 10:47:18.469 [3836] DEBUG - DVR:Grabber: Failed to retrieve device data
Sep 13, 2019 10:49:01.772 [1636] DEBUG - BPQ: [Starting] -> [Processing]
Sep 13, 2019 10:49:01.803 [1636] DEBUG - BPQ: generating queue items from 0 generator(s)
Sep 13, 2019 10:49:01.803 [1636] DEBUG - BPQ: generated 0 item(s) for queue
Sep 13, 2019 10:49:01.803 [1636] ERROR - SQLITE3:0xc76f2bdc, 8, statement aborts at 1: [BEGIN IMMEDIATE] attempt to write a readonly database
Sep 13, 2019 10:49:01.803 [1636] ERROR - Failed to begin transaction (…\BackgroundProcessing\BackgroundProcessingQueue.cpp:41) (tries=1): Cannot begin transaction. attempt to write a readonly database
Sep 13, 2019 10:49:02.865 [1636] ERROR - SQLITE3:0xc76f2bdc, 8, statement aborts at 1: [BEGIN IMMEDIATE] attempt to write a readonly database
Sep 13, 2019 10:49:02.865 [1636] ERROR - Failed to begin transaction (…\BackgroundProcessing\BackgroundProcessingQueue.cpp:41) (tries=2): Cannot begin transaction. attempt to write a readonly database
Sep 13, 2019 10:49:04.000 [1636] ERROR - SQLITE3:0xc76f2bdc, 8, statement aborts at 1: [BEGIN IMMEDIATE] attempt to write a readonly database
Sep 13, 2019 10:49:04.000 [1636] ERROR - Failed to begin transaction (…\BackgroundProcessing\BackgroundProcessingQueue.cpp:41) (tries=3): Cannot begin transaction. attempt to write a readonly database
Sep 13, 2019 10:49:04.282 [1636] ERROR - SQLITE3:0xc76f2bdc, 8, statement aborts at 1: [BEGIN IMMEDIATE] attempt to write a readonly database
Sep 13, 2019 10:49:04.282 [1636] ERROR - Failed to begin transaction (…\BackgroundProcessing\BackgroundProcessingQueue.cpp:41) (tries=4): Cannot begin transaction. attempt to write a readonly database
Sep 13, 2019 10:49:04.828 [1636] ERROR - SQLITE3:0xc76f2bdc, 8, statement aborts at 1: [BEGIN IMMEDIATE] attempt to write a readonly database
Sep 13, 2019 10:49:04.828 [1636] ERROR - Failed to begin transaction (…\BackgroundProcessing\BackgroundProcessingQueue.cpp:41) (tries=5): Cannot begin transaction. attempt to write a readonly database
Sep 13, 2019 10:49:05.909 [1636] ERROR - SQLITE3:0xc76f2bdc, 8, statement aborts at 1: [BEGIN IMMEDIATE] attempt to write a readonly database
Sep 13, 2019 10:49:05.909 [1636] ERROR - Failed to begin transaction (…\BackgroundProcessing\BackgroundProcessingQueue.cpp:41) (tries=6): Cannot begin transaction. attempt to write a readonly database
Sep 13, 2019 10:49:07.081 [1636] ERROR - SQLITE3:0xc76f2bdc, 8, statement aborts at 1: [BEGIN IMMEDIATE] attempt to write a readonly database
Sep 13, 2019 10:49:07.081 [1636] ERROR - Failed to begin transaction (…\BackgroundProcessing\BackgroundProcessingQueue.cpp:41) (tries=7): Cannot begin transaction. attempt to write a readonly database
Sep 13, 2019 10:49:07.425 [1636] ERROR - SQLITE3:0xc76f2bdc, 8, statement aborts at 1: [BEGIN IMMEDIATE] attempt to write a readonly database
Sep 13, 2019 10:49:07.425 [1636] ERROR - Failed to begin transaction (…\BackgroundProcessing\BackgroundProcessingQueue.cpp:41) (tries=8): Cannot begin transaction. attempt to write a readonly database
Sep 13, 2019 10:49:08.110 [1636] ERROR - SQLITE3:0xc76f2bdc, 8, statement aborts at 1: [BEGIN IMMEDIATE] attempt to write a readonly database
Sep 13, 2019 10:49:08.110 [1636] ERROR - Failed to begin transaction (…\BackgroundProcessing\BackgroundProcessingQueue.cpp:41) (tries=9): Cannot begin transaction. attempt to write a readonly database
Sep 13, 2019 10:49:08.510 [1636] ERROR - SQLITE3:0xc76f2bdc, 8, statement aborts at 1: [BEGIN IMMEDIATE] attempt to write a readonly database
Sep 13, 2019 10:49:08.510 [1636] ERROR - Failed to begin transaction (…\BackgroundProcessing\BackgroundProcessingQueue.cpp:41) (tries=10): Cannot begin transaction. attempt to write a readonly database
Sep 13, 2019 10:49:08.510 [1636] ERROR - Thread: Uncaught exception running async task which was spawned by thread 3936: Cannot begin transaction. attempt to write a readonly database
Sep 13, 2019 10:50:08.044 [3932] ERROR - Timeout or error reading status line from plug-in pipe [com.plexapp.system], we’re killing it.
Sep 13, 2019 10:50:08.044 [3932] DEBUG - Stopping [com.plexapp.system].
Sep 13, 2019 10:50:08.044 [3932] DEBUG - [com.plexapp.system] Killing.
Sep 13, 2019 10:50:08.044 [3932] ERROR - Error received reading configuration for com.plexapp.system
Sep 13, 2019 10:50:08.044 [3932] DEBUG - Stopping [com.plexapp.system].
Sep 13, 2019 10:50:08.044 [3932] DEBUG - Done with 1 synchronous plug-in starts, starting the rest in parallel.
Sep 13, 2019 10:50:08.044 [3932] DEBUG - PluginRepository::setStartState: 2, startingPlugins
Sep 13, 2019 10:50:08.044 [3932] DEBUG - Updating the list of agents known by the system.
Sep 13, 2019 10:50:08.044 [3932] DEBUG - Starting file watcher for com.plexapp.system
Sep 13, 2019 10:50:08.044 [3780] DEBUG - Image transcode cache directory: “Q:\Arnie\Plex Media Server\Cache\PhotoTranscoder”
Sep 13, 2019 10:50:08.044 [3780] DEBUG - Transcoder: Cleaning old transcode directories.
Sep 13, 2019 10:50:08.044 [3932] DEBUG - Plugin::createProcess: Creating plugin process: “C:\Program Files (x86)\Plex\Plex Media Server\PlexScriptHost.exe” “C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-1e5ff713d\Framework.bundle\Contents\Resources\Versions\2\Python\bootstrap.py” “C:\Program Files (x86)\Plex\Plex Media Server\Resources\Plug-ins-1e5ff713d\System.bundle”
Sep 13, 2019 10:50:08.044 [3932] DEBUG - Spawned plug-in com.plexapp.system with PID 772
Sep 13, 2019 10:50:08.044 [3932] DEBUG - [com.plexapp.system] Sending command: GET /:/prefixes
Sep 13, 2019 10:50:08.560 [3780] ERROR - SQLITE3:0xc76f2bdc, 8, statement aborts at 26: [update external_metadata_sources set online=0] attempt to write a readonly database
