Server Version#: 1.28.2.6151
Player Version#: 4.89.1
app.plex.tv is unable to securely connect to my server 50% of the time. I’ve been having to fall back to the insecure local bundled web app much more often, as the issue has continued to increase in frequency. Is there any fix to make secure connections always work, so the web app and all other apps will be functional?
Plex Media Server Logs_2022-08-30_20-50-51.zip (5.0 MB)
The biggest issue I see in your logs is that the server is kept nearly constantly busy performing a full scan of section 9 (/volume2/Music)
Every few minutes it starts a new scan, just as it finishes the previous scan.
Do you have something writing files in there ?
Also, it doesn’t seem you have “Partial Scan” enabled (Settings - Library)
as that would greatly reduce the scanning time.
Also, please turn off VERBOSE logging. That wastes a ton of CPU we do not need
Whenever I’m adding to my music collection, I will run the files through a program called AudioRanger Pro to auto-tag and collate/organize the files into the “/Music/Sorted and Tagged” folder. As the RAID array that contains my music collection is SMR, the write speed is usually 8 - 10 MBps, so only a few songs at a time are added to the folder for the scanner to work on. I disabled partial scan because with it on the server was often missing/never adding tracks, but I’ll turn it back on. Verbose logging was disabled before I created the logs, but it would have been on for any already made, I assume.
How many folders do you have for Music?
The biggest reason “When changes are detected” fails is because there are more folders in use than the default provided by the Linux kernel (DSM uses Linux)
There is an easy remedy for this so you can have Partial and When detected work as they should. You won’t need periodic & full anymore.
Increasing the number of folders with the guide did not help.
Please make certain DEBUG logging is enabled, VERBOSE is disabled, SAVE if you make changes.
Restart PMS
Wait two minute (complete inactivity)
Now recreate / capture what you can.
Download the logs ZIP file and attach here please.
Q: Are you using your own certificate anywhere (your own FQDN or a self-signed certificate from the Syno) ?
The issue reoccurred a minute before I made the log .ZIP. I don’t use my own certificate.
Plex Media Server Logs_2022-09-12_16-12-13.zip (4.8 MB)
Please turn of Synology QuickConnect if you can and retest.
I think it’s causing the problem based on your logs.
Seems to be working for now. I’ll mark as the solution if it doesn’t happen for a few days.
The server is still going offline.
Please do the following:
Logs.zip (7.9 MB)
Here are the logs requested. I triggered a full library scan 8 minutes after launch. The server did not go offline until the scan was underway. No other activity (R/W) was occurring on the hard drives at the time.
May I ask where the rest of the logs are ? (Plex Media Server.*.log)
Matcher & analysis logs are of no benefit here.
I am seeing where PMS hasn’t finished setup and it’s already being tasked.
From there, it degrades until it can no longer respond to anything.
I think the “flipping” you’re seeing is the players timing out. They are failing to get a response from the server within the time limit so bark out the ‘unsecure’ message.
What I see.
Sep 23, 2022 07:27:44.289 [0x7f773136bb00] INFO - Plex Media Server v1.28.2.6151-914ddd2b3 - Synology DS920+ x86_64 - build: linux-x86_64 synology-dsm7 - GMT -05:00
Sep 23, 2022 07:27:44.289 [0x7f773136bb00] INFO - Linux version: DSM 7.1.42661-4, language: en-US
Sep 23, 2022 07:27:44.289 [0x7f773136bb00] INFO - Processor: 4-core Intel(R) Celeron(R) J4125 CPU @ 2.00GHz
Sep 23, 2022 07:29:37.874 [0x7f772c3cdb00] WARN - Waited one whole second for a busy database.
Sep 23, 2022 07:29:37.899 [0x7f772e760b00] DEBUG - [HttpClient/HCl#33] HTTP/2.0 (0.1s) 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx (reused)
Sep 23, 2022 07:29:37.899 [0x7f772c9d6b00] DEBUG - [MediaProviderManager] discovered cloud provider (Movies & TV)
Sep 23, 2022 07:29:37.899 [0x7f772c9d6b00] DEBUG - [MediaProviderManager] discovered cloud provider (Music)
Sep 23, 2022 07:29:37.899 [0x7f772c9d6b00] DEBUG - [MediaProviderManager] discovered cloud provider (Metadata)
Sep 23, 2022 07:29:37.899 [0x7f772c9d6b00] DEBUG - [MediaProviderManager] loading cloud provider details (Metadata) (alive: 1)
Sep 23, 2022 07:29:37.899 [0x7f772c9d6b00] DEBUG - [MediaProviderManager] loading cloud provider details (Music) (alive: 1)
Sep 23, 2022 07:29:37.899 [0x7f772c9d6b00] DEBUG - [MediaProviderManager] loading cloud provider details (Movies & TV) (alive: 1)
Sep 23, 2022 07:29:37.899 [0x7f772c9d6b00] DEBUG - [MediaProviderManager] we had 3 cloud providers online, we now have 3
Sep 23, 2022 07:29:37.899 [0x7f772c9d6b00] DEBUG - [MediaProviderManager] cloud provider (Metadata) is online and available
Sep 23, 2022 07:29:37.899 [0x7f772c9d6b00] DEBUG - [MediaProviderManager] cloud provider (Music) is online and available
Sep 23, 2022 07:29:37.899 [0x7f772c9d6b00] DEBUG - [MediaProviderManager] cloud provider (Movies & TV) is online and available
Sep 23, 2022 07:29:37.907 [0x7f772e760b00] DEBUG - [HttpClient/HCl#34] HTTP/2.0 (0.2s) 200 response from GET https://plex.tv/api/v2/server/users/subscriptions?auth_token=xxxxxxxxxxxxxxxxxxxx (reused)
Sep 23, 2022 07:29:38.221 [0x7f772afafb00] DEBUG - MyPlex: using cached data for request for https://plex.tv/api/v2/server/users/services?auth_token=xxxxxxxxxxxxxxxxxxxx
Sep 23, 2022 07:29:39.564 [0x7f772bfc7b00] DEBUG - [Notify] Now watching "/volume1/Video/Ready For Plex/TV Shows"
Sep 23, 2022 07:29:39.612 [0x7f772bfc7b00] DEBUG - [Notify] Now watching "/volume1/Video/Ready For Plex/TV Shows/Hell's Kitchen (U.S.)"
Sep 23, 2022 07:29:39.760 [0x7f772bfc7b00] DEBUG - [Notify] Now watching "/volume1/Video/Ready For Plex/TV Shows/Hell's Kitchen (U.S.)/Season 1"
Sep 23, 2022 07:29:39.760 [0x7f772bfc7b00] DEBUG - [Notify] Now watching "/volume1/Video/Ready For Plex/TV Shows/Hell's Kitchen (U.S.)/Season 2"
Sep 23, 2022 07:29:39.859 [0x7f772bfc7b00] DEBUG - [Notify] Now watching "/volume1/Video/Ready For Plex/TV Shows/Hell's Kitchen (U.S.)/Season 3"
Sep 23, 2022 07:29:39.879 [0x7f772bfc7b00] DEBUG - [Notify] Now watching "/volume1/Video/Ready For Plex/TV Shows/Hell's Kitchen (U.S.)/Season 4"
Sep 23, 2022 07:30:48.731 [0x7f772bfc7b00] DEBUG - [Notify] Now watching "/volume1/Video/Ready For Plex/TV Shows/Law and Order - Special Victims Unit/Season 23"
Sep 23, 2022 07:30:49.108 [0x7f772bfc7b00] DEBUG - [Notify] Now watching "/volume1/Video/Ready For Plex/TV Shows/Law and Order - Special Victims Unit/Season 5"
Sep 23, 2022 07:30:50.725 [0x7f77351011c0] WARN - [DatabaseFixups] Held transaction for too long (/data/jenkins/server/3535474905/Library/DatabaseFixups.cpp:375): 0.920000 seconds
Sep 23, 2022 07:30:50.725 [0x7f77351011c0] DEBUG - [DatabaseFixups] Running database fix-ups completed in 2.2 seconds.
Sep 23, 2022 07:30:50.725 [0x7f772d939b00] WARN - Took too long (0.680000 seconds) to start a transaction on /data/jenkins/server/3535474905/Statistics/StatisticsManager.cpp:252
Sep 23, 2022 07:30:50.725 [0x7f772d939b00] WARN - Transaction that was running was started on thread 0x7f77351011c0 at /data/jenkins/server/3535474905/Library/DatabaseFixups.cpp:357
Sep 23, 2022 07:30:50.809 [0x7f77351011c0] DEBUG - [HCl#35] HTTP requesting GET https://plex.tv/api/v2/user/privacy?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 23, 2022 07:30:51.630 [0x7f772bfc7b00] DEBUG - [Notify] Now watching "/volume1/Video/Ready For Plex/TV Shows/Law and Order - Special Victims Unit/Season 6"
Sep 23, 2022 07:30:51.681 [0x7f772e760b00] DEBUG - [HttpClient/HCl#35] HTTP/2.0 (0.9s) 200 response from GET https://plex.tv/api/v2/user/privacy?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 23, 2022 07:30:52.010 [0x7f77351011c0] DEBUG - [HCl#36] HTTP requesting GET https://plex.tv/api/v2/features?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Sep 23, 2022 07:30:52.191 [0x7f772e760b00] DEBUG - [HttpClient/HCl#36] HTTP/2.0 (0.2s) 200 response from GET https://plex.tv/api/v2/features?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx (reused)
Sep 23, 2022 07:30:52.213 [0x7f772adacb00] WARN - [Req#4d] Took too long (0.560000 seconds) to start a transaction on /data/jenkins/server/3535474905/Statistics/Device.cpp:46
Sep 23, 2022 07:30:52.213 [0x7f772adacb00] WARN - [Req#4d] Transaction that was running was started on thread 0x7f772d939b00 at /data/jenkins/server/3535474905/Statistics/StatisticsManager.cpp:252
Sep 23, 2022 07:30:52.213 [0x7f77351011c0] DEBUG - Waiting for server condition to be signaled.
Sep 23, 2022 07:31:46.186 [0x7f772d939b00] DEBUG - Request: [73.115.XXX.XXX]
Sep 23, 2022 07:34:39.284 [0x7f7725ab6b00] DEBUG - 17 threads are waiting on db connections held by threads: 0x7f7723684b00,0x7f7725128b00,0x7f77295e2b00,0x7f7727f84b00,0x7f7728417b00,0x7f772a83db00,0x7f772c4b4b00,0x7f7724f25b00,0x7f772a27db00,0x7f7726a15b00,0x7f77207feb00,0x7f7729c2bb00,0x7f7725fecb00,0x7f772aa40b00,0x7f772764eb00,0x7f772c7deb00,0x7f772adacb00,0x7f7726e1bb00,0x7f7725823b00,0x7f7724621b00
Sep 23, 2022 07:34:39.284 [0x7f772aa40b00] DEBUG - There were 1 top-level paths for Big Brother (US).
Sep 23, 2022 07:34:39.285 [0x7f772aa40b00] DEBUG - 17 threads are waiting on db connections held by threads: 0x7f7723684b00,0x7f7725128b00,0x7f77295e2b00,0x7f7727f84b00,0x7f7728417b00,0x7f772a83db00,0x7f772c4b4b00,0x7f7724f25b00,0x7f772a27db00,0x7f7726a15b00,0x7f77207feb00,0x7f7729c2bb00,0x7f7725fecb00,0x7f7729e2eb00,0x7f772764eb00,0x7f772c7deb00,0x7f772adacb00,0x7f7726e1bb00,0x7f7725823b00,0x7f7724621b00
Sep 23, 2022 07:34:39.329 [0x7f7723115b00] INFO - [Req#3c8] AutoUpdate: no updates available
Sep 23, 2022 07:34:39.330 [0x7f7730d0ab00] DEBUG - Completed: [192.168.4.120:1413] 200 PUT /updater/check?download=0 (41 live) TLS GZIP 1241ms 320 bytes (pipelined: 2)
Sep 23, 2022 07:34:39.340 [0x7f772adacb00] DEBUG - Activity: updated activity 4c7fcc7e-019a-4d04-a97c-b6e8de43d798 - completed 0.0% - Scanning TV Shows
Sep 23, 2022 07:34:39.340 [0x7f772adacb00] DEBUG - 18 threads are waiting on db connections held by threads:
Sep 23, 2022 07:34:41.343 [0x7f772660fb00] DEBUG - [Req#3b9] Created thumbnail of size 240x240, has pixels: 1
Sep 23, 2022 07:34:41.348 [0x7f77297e5b00] WARN - [Req#3f2/Req#3fa] SLOW QUERY: It took 230.000000 ms to retrieve 1 items.
Sep 23, 2022 07:34:41.349 [0x7f7723abab00] WARN - [Req#3e9/Req#3f6] SLOW QUERY: It took 300.000000 ms to retrieve 1 items.
Sep 23, 2022 07:34:41.427 [0x7f7730d0ab00] DEBUG - Completed: [[fd5c:9c5f:ff63:1:58a2:c20f:c439:2d09]:1382] 200 GET /photo/:/transcode
Sep 23, 2022 07:34:42.801 [0x7f772bfc7b00] DEBUG - [Notify] Now watching "/volume1/Video/Ready For Plex/TV Shows/Brooklyn Nine-Nine/Season 6"
Sep 23, 2022 07:34:42.809 [0x7f7723115b00] WARN - [Req#414/Req#416] SLOW QUERY: It took 530.000000 ms to retrieve 1 items.
Sep 23, 2022 07:34:42.809 [0x7f7725de9b00] WARN - [Req#40f/Req#410] SLOW QUERY: It took 950.000000 ms to retrieve 1 items.
Sep 23, 2022 07:34:42.809 [0x7f772aa40b00] WARN - [Req#417/Req#41b] SLOW QUERY: It took 440.000000 ms to retrieve 1 items.
Sep 23, 2022 07:34:42.809 [0x7f7723cddb00] WARN - [Req#3fb/Req#40c] SLOW QUERY: It took 1440.000000 ms to retrieve 1 items.
Sep 23, 2022 07:34:42.810 [0x7f7723f60b00] WARN - [Req#413/Req#415] SLOW QUERY: It took 550.000000 ms to retrieve 1 items.
Sep 23, 2022 07:34:42.810 [0x7f7725ab6b00] WARN - [Req#419/Req#41d] SLOW QUERY: It took 280.000000 ms to retrieve 1 items.
Sep 23, 2022 07:34:42.843 [0x7f7723887b00] DEBUG - [Req#41f/Req#425] 6 threads are waiting on db connections held by threads:
Sep 23, 2022 07:35:43.580 [0x7f772bfc7b00] DEBUG - [Notify] Now watching "/volume2/Music/Sorted and Tagged/Compilations/Take Me Back (The Remixes)"
Sep 23, 2022 07:35:43.675 [0x7f772a294b00] DEBUG - Activity: updated activity 1dbb955f-80bc-4c15-835c-91043a541393 - completed 85.1% - Detecting intros
Sep 23, 2022 07:59:09.400 [0x7f773114fb00] DEBUG - Jobs: '/volume1/@appstore/PlexMediaServer/Plex Media Scanner' exit code for process 12359 is 0 (success)
Sep 23, 2022 07:59:09.654 [0x7f77207feb00] WARN - SLOW QUERY: It took 5470.000000 ms to retrieve 1 items.
Sep 23, 2022 07:59:10.051 [0x7f772c1eab00] DEBUG - Activity: Ended activity a103058b-1c44-4cea-942d-9bed45160e66.
Sep 23, 2022 07:59:10.224 [0x7f772c1eab00] DEBUG - Activity: registered new activity b082d3e6-9a24-4432-9f6b-5b8bce8fa1c1 - "Generating loudness data"
Sep 23, 2022 07:59:10.224 [0x7f772c1eab00] DEBUG - [JobRunner] Job running: FFMPEG_EXTERNAL_LIBS='/var/packages/PlexMediaServer/shares/PlexMediaServer/AppData/Plex\ Media\ Server/Codecs/c4efa15-4365-linux-x86_64/' X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxx "/volume1/@appstore/PlexMediaServer/Plex Media Scanner" --analyze-loudness --item 326648 --log-file-suffix " Deep Analysis"
Sep 23, 2022 07:59:10.475 [0x7f772c1eab00] DEBUG - [JobRunner] Jobs: Starting child process with pid 12435
Sep 23, 2022 07:59:26.288 [0x7f773114fb00] DEBUG - Jobs: '/volume1/@appstore/PlexMediaServer/Plex Media Scanner' exit code for process 12435 is 0 (success)
Sep 23, 2022 07:59:26.864 [0x7f77207feb00] WARN - SLOW QUERY: It took 1820.000000 ms to retrieve 1 items.
Sep 23, 2022 07:59:27.042 [0x7f772c1eab00] DEBUG - Activity: Ended activity b082d3e6-9a24-4432-9f6b-5b8bce8fa1c1.
Sep 23, 2022 07:59:27.080 [0x7f772c1eab00] DEBUG - Activity: registered new activity a2b9242c-9d48-4311-bc0c-b8dd1d3ebe58 - "Generating loudness data"
Sep 23, 2022 07:59:27.080 [0x7f772c1eab00] DEBUG - [JobRunner] Job running: FFMPEG_EXTERNAL_LIBS='/var/packages/PlexMediaServer/shares/PlexMediaServer/AppData/Plex\ Media\ Server/Codecs/c4efa15-4365-linux-x86_64/' X_PLEX_TOKEN=xxxxxxxxxxxxxxxxxxxx "/volume1/@appstore/PlexMediaServer/Plex Media Scanner" --analyze-loudness --item 326650 --log-file-suffix " Deep Analysis"
Sep 23, 2022 07:59:27.287 [0x7f772c1eab00] DEBUG - [JobRunner] Jobs: Starting child process with pid 12476
Sep 23, 2022 07:59:33.441 [0x7f772dd44b00] DEBUG - Putting plug-in com.plexapp.agents.imdb to sleep.
Sep 23, 2022 07:59:33.505 [0x7f772dd44b00] DEBUG - Stopping [com.plexapp.agents.imdb].
Sep 23, 2022 07:59:33.505 [0x7f772dd44b00] DEBUG - [com.plexapp.agents.imdb] Killing.
Sep 23, 2022 07:59:33.567 [0x7f773114fb00] WARN - JobManager: Could not find job for handle 3399
Sep 23, 2022 07:59:33.652 [0x7f77207feb00] WARN - SLOW QUERY: It took 2960.000000 ms to retrieve 1 items.
I suspect this is 99.9% database
A few questions:
Oops, sorry. I grabbed the logs manually because the server was unresponsive. Grabbed them with the web client now.
BTW, I decided to buy a new computer to run the server on that’s slightly more powerful. It hasn’t crashed yet, but still has 1800 albums to do the Sonic Analysis on and is Detecting Intros. (Same CPU, but it supports the Intel Quick Sync driver that wasn’t available on DSM).
Now I’m confused.
(Same CPU, but it supports the Intel Quick Sync driver that wasn’t available on DSM).
Did you just move the server from Synology to another OS or has this been a XPEnology the entire time?
I also have a suggestion for you.
Just moved it. Did step 2 too. I might close this thread because I decided to move off of Synology.
As you wish.
If you decide to close it, please make a closing post and mark as the solution.
Moved the server from Synology to Windows 11 because it kept crashing on Synology.
