Plex crashes randomly after latest update

Plex Media Server
1

Server Version#: 1.22.0.4163
Player Version#: N/A

I currently have Plex running the only build that has been stable for me which is noted above that has come out in the last month. All of the newest beta releases cause constant crashing and restarting (the service) can take as long as 3 minutes (used to be near instant).

I haven’t seen anything in the logs to indicate what’s happening, the streams indicator also takes several minutes to populate if it does at all (even though there are streams going). Trying to obtain logs of when the server crashes occur may prove difficult as well because it just happens - doesn’t matter how many streams are going, there’s no specific scenario where it happens.

Prior to the builds that use the new TV agent - my system ran flawlessly.

OS: Ubuntu 16
Kernel: 4.15.0-139-generic
CPU: 2X Intel(R) Xeon(R) Silver 4116
RAM: 32GB

2

so… would you mind sharing your logs or are you just stating that it’s unstable for you? :wink:

3

Lol… I knew this was going to happen.
Like I stated in my post, I’ll have to wait for a crash so I can try to obtain logs. To my knowledge, logs are wiped after restarting the service - typically I’m in more of a rush to get up and running than I am trying to figure out what happened.

When it crashes again, I’ll try to get what logs I can. Web UI is also out of commission when this happens so I can’t just download the zip.

4

With how things have been over this past week, I’ll likely have logs in an hour or two (unless it’s nice to me tonight).

5

@tom80H should be able to verify, but if you are running Plex on bare metal, the logs shouldn’t get wiped when the service is restarted (incorrect Docker setup could potentially mean no persistent data but that would mean you’d have to recreate your libraries each time the system restarts as well). That would be an extremely dumb decision as it would make troubleshooting super hard (and if it is the case I am going to say that it is an extremely dumb decision, but I don’t think that’s the case).

If the Web UI is not functional after it crashes, you should be able to get the logs directly from

$PLEX_HOME/Library/Application Support/Plex Media Server/Logs

(I got that location from here, Crash Logs: Plex Media Server | Plex Support just changed the Crash Logs to Logs at the end as they are under the same location)

You can tar/zip them yourself and then upload them here (that’s essentially all the option from the Web UI does from what I can gather).

Edit since I see @ChuckPa replying. He should also be able to verify what I just said, or smack me for giving false info :rofl:.

-Shark2k

6

Logs from previous plex starts are stored automatically. Please go to plex settings/troubleshooting and click download logs.

7

I agree, it would be incredibly dumb - but I’m almost positive I read it here in the forum somewhere. At one point I was looking into increasing how many logs are kept, and I ran into that.

If they are in-fact kept through restarts, then I’ll happily upload them. I only recently turned on debugging though and I don’t believe it’s crashed since then.

1 Like
8

Here are the logs Plex Media Server Logs_2021-03-25_20-45-17.zip (6.0 MB)

9

If there are no signs of a crash in that log, I’ll have to wait for another crash to upload them again. Should I leave debugging on or turn it off?

10

If I may augment ?

PMS 1.22.1.4200 & 4288 brought database changes.
Those changes weren’t simple schema changes.
The changes required the entire DB be scanned and values to be changed.

The size of the database (number of items indexed) and the speed of the CPU determine how long it takes to complete those changes.

I have only 27,000 entries and an i7-7700 CPU with 64 GB of RAM and it took my system almost 4 minutes to complete startup the first time.

There are some folks with 300,000 indexed items who waited nearly an hour for PMS to start responding

Engineering didn’t really communicate that well, for which I will apologize .
We in support didn’t have any understanding of it either until after it went to PlexPass beta.

There is currently an issue with hardware transcoding on older (Ubuntu 18 and lower / Debian 9 and older) systems.

I was able to track that down today and submitted to Engineering for resolution.

4 Likes
11

That would have been reallllly great to know. Thank you for telling me.

HW transcoding shouldn’t be a variable, I don’t use it.

12

Knowing about the database changes, I’ll try to update tomorrow morning to the new version and let things run their course. That still to me doesn’t really explain the sudden instability though, unless that and the stream indicator are all just bi-products?

13

When you say instability, my next question would be "What’s unstable ? ".

There are a lot of moving parts. Can you point to something specific ?

I know of so many changes which came together in these past few versions it is possible they might have converged in your case. Nothing is impossible.

The biggest changes however are transcoding and the database.

14

In terms of stability, after updating beyond this version I found I wasn’t able to access the web UI right away like I was used to. That could be accounted for by the database changes though that you mentioned, I’ve got a large database and wasn’t accounting for the fact it could take a while before server would be accessible again.

I get the feeling my case is just updating and not letting things take their proper course, getting frustrated it’s “not working” I’ll stop the service and try restarting it, rinse and repeat once more before rolling back to a previous version.

I imagine any crashes I encounter from my now until I update again could be due to flip flopping versions multiple times and not letting the database changes finish.

15

I feel like the database changes just need to complete and things will be smooth sailing again. I’ll update in the morning and mark your initial mentioning of the database changes as the solution once I confirm it’s up and running for a bit.

16

I’ve also had issues in the last week or two where I was stable for ~3 years. Now my server is constantly becoming unresponsive / going down with plex (according to logs ive seen so far) showing no sign of an issue.

The only solution is to restart and wait for it to happen again.

It introduced the following issues for me:

  • Server becomes totally unresponsive over an undetermined period of time
  • Playback now seems to break if you let a client sit for too long (e.g. a web client would have to reload for playback to work)
  • Overall lag in loading anything has definitely increased

I’ve attached my logs to see if it helps the investigation here.

Plex Media Server Logs_2021-03-25_22-00-44.zip (3.3 MB)

1 Like
17

Thank you for those logs but you did one thing which makes it impossible for me to figure out what’s happening; You turned off DEBUG logging.

I only got bunched of lines of this:

Mar 24, 2021 06:00:13.936 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:14.037 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:14.037 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:14.137 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:14.137 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:14.237 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:14.237 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:14.337 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:14.337 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:14.437 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:14.437 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:14.537 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:14.537 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:14.637 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:14.637 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:14.737 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:14.737 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:14.837 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:14.837 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:14.937 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:14.937 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:15.037 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:15.037 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:15.138 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:15.138 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1
Mar 24, 2021 06:00:15.238 [0x728ffa5d3700] INFO - Network Service: Abandoning browse socket, it was closed.
Mar 24, 2021 06:00:15.936 [0x728ffa5d3700] ERROR - Network Service: Error in browser handle read: 125 (Operation canceled) socket=-1

with no indication what it’s for.

I do see some SLOW QUERY – indicative of a very loaded (almost overloaded) machine state – memory contention – or DB fragmentation (needing optimization)

Mar 24, 2021 09:52:17.706 [0x728fd5d35700] INFO - Library section 2 (Shows) will be updated because of a change in "/home/plex/media_remote/n1/shows/Superstore"
Mar 24, 2021 09:52:17.734 [0x728fd5d35700] INFO - Library section 2 (Shows) will be updated because of a change in "/home/plex/media_remote/n1/shows/Superstore/Season 6"
Mar 24, 2021 09:52:17.892 [0x728fd5d35700] INFO - Library section 2 (Shows) will be updated because of a change in "/home/plex/media_remote/n1/shows/Superstore/Season 6/Superstore - S06E01 - Essential.mkv"
Mar 24, 2021 09:52:54.901 [0x728fd5d35700] INFO - Library section 2 (Shows) will be updated because of a change in "/home/plex/media_remote/n1/shows/Superstore/Season 6/Superstore - S06E01 - Essential.mkv"
Mar 24, 2021 09:53:09.398 [0x728f75d58700] WARN - SLOW QUERY: It took 210.000000 ms to retrieve 51 items.
Mar 24, 2021 09:53:09.447 [0x728f77723700] WARN - SLOW QUERY: It took 440.000000 ms to retrieve 50 items.
Mar 24, 2021 09:53:10.603 [0x728fd5d35700] INFO - Library section 2 (Shows) will be updated because of a change in "/home/plex/media_remote/n1/shows/Superstore/Season 6/Superstore - S06E05 - Hair Care Products.mkv"
Mar 24, 2021 09:53:10.992 [0x728f7545e700] WARN - MDE: unable to find a working transcode profile for video stream
Mar 24, 2021 09:53:10.993 [0x728f7545e700] WARN - MDE: unable to find a working transcode profile for video stream
Mar 24, 2021 09:53:11.230 [0x728f76eac700] WARN - SLOW QUERY: It took 270.000000 ms to retrieve 50 items.
Mar 24, 2021 09:53:13.782 [0x728f7661a700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Mar 24, 2021 09:53:13.782 [0x728f7661a700] WARN - QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Mar 24, 2021 09:53:13.785 [0x728f7661a700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Mar 24, 2021 09:53:13.785 [0x728f7661a700] WARN - QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Mar 24, 2021 09:53:13.912 [0x728f76eac700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Mar 24, 2021 09:53:13.912 [0x728f76eac700] WARN - QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Mar 24, 2021 09:53:14.049 [0x72901a600700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Mar 24, 2021 09:53:14.049 [0x72901a600700] WARN - QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Mar 24, 2021 09:53:14.051 [0x72901a600700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Mar 24, 2021 09:53:14.051 [0x72901a600700] WARN - QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Mar 24, 2021 09:53:14.783 [0x728f7661a700] WARN - QueryParser: Invalid field 'contentDirectoryID' found, ignoring.
Mar 24, 2021 09:53:14.783 [0x728f7661a700] WARN - QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Mar 24, 2021 09:53:14.783 [0x728f7661a700] WARN - QueryParser: Invalid field 'onlyTransient' found, ignoring.
Mar 24, 2021 09:53:15.083 [0x728f76eac700] WARN - QueryParser: Invalid field 'identifier' found, ignoring.
Mar 24, 2021 09:53:15.083 [0x728f76eac700] WARN - QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Mar 24, 2021 09:53:15.083 [0x728f76eac700] WARN - QueryParser: Invalid field 'onlyTransient' found, ignoring.
Mar 24, 2021 09:53:15.086 [0x728f76eac700] WARN - QueryParser: Invalid field 'identifier' found, ignoring.
Mar 24, 2021 09:53:15.086 [0x728f76eac700] WARN - QueryParser: Invalid field 'libraryHubsOnly' found, ignoring.
Mar 24, 2021 09:53:15.086 [0x728f76eac700] WARN - QueryParser: Invalid field 'onlyTransient' found, ignoring.
Mar 24, 2021 09:53:15.236 [0x728fb6e5a700] WARN - SLOW QUERY: It took 410.000000 ms to retrieve 50 items.
Mar 24, 2021 09:53:15.251 [0x728f6b6c6700] WARN - SLOW QUERY: It took 240.000000 ms to retrieve 51 items.
Mar 24, 2021 09:53:15.288 [0x728f6a62d700] WARN - SLOW QUERY: It took 380.000000 ms to retrieve 50 items.
Mar 24, 2021 09:53:29.557 [0x728f77723700] ERROR - Error issuing curl_easy_perform(handle): 28
Mar 24, 2021 09:53:29.557 [0x728f77723700] ERROR - Error parsing content.
Mar 24, 2021 09:53:29.603 [0x728f77723700] ERROR - Error parsing XML response for update.
Mar 24, 2021 09:53:49.714 [0x728fd5d35700] INFO - Library section 2 (Shows) will be updated because of a change in "/home/plex/media_remote/n1/shows/Superstore/Season 6/Superstore - S06E05 - Hair Care Products.mkv"
Mar 24, 2021 09:53:49.972 [0x728f7659d700] WARN - SLOW QUERY: It took 220.000000 ms to retrieve 51 items.
Mar 24, 2021 09:53:49.996 [0x728f77723700] WARN - SLOW QUERY: It took 340.000000 ms to retrieve 50 items.```

FWIW:  This Xeon should be as crisp as an i7-7700 and this is very slow.   340 items queried should take fewer than 10 milliseconds    not 340.


If there's any way for you to 
1.  Enable DEBUG logging again,  keeping VERBOSE off
2.  Finding a way to recreate anything you're seeing.
3.  Download the logs right after doing so
4.  Uploading that ZIP file here.
5.  I will go through it and see what I can find .
18

I’ve just recently updated my plex server and have crashing as well.

Plex Media Server.zip (523.7 KB)

19

@chazof99

Your issue shows the player having a problem.

Mar 25, 2021 21:43:00.604 [0x145c8db40700] DEBUG - Auth: authenticated user 65197013 as Wife
Mar 25, 2021 21:43:00.604 [0x145c8c736700] DEBUG - Request: [192.168.201.249:57694 (WAN)] GET /library/parts/2438/1503616629/file.mp4?autoAdjustQuality=0&hasMDE=1&location=lan&mediaBufferSize=74944 (23 live) TLS Signed-in Token (Wife) (range: bytes=222367036-) 
Mar 25, 2021 21:43:00.610 [0x145c8c736700] DEBUG - Content-Length of /data/Shows/Battlestar Galactica (2003)/Season 2/Battlestar Galactica (2003) - S02E18 - Downloaded.mp4 is 74 (of total: 222367110).
Mar 25, 2021 21:43:00.626 [0x145c8db40700] DEBUG - Completed: [192.168.201.249:57694] 206 GET /library/parts/2438/1503616629/file.mp4?autoAdjustQuality=0&hasMDE=1&location=lan&mediaBufferSize=74944 (23 live) TLS 21ms 74 bytes (range: bytes=222367036-) 
Mar 25, 2021 21:43:00.628 [0x145c8dd41700] DEBUG - Failed to stream media, client probably disconnected after 6963200 bytes: 104 - Connection reset by peer
Mar 25, 2021 21:43:00.629 [0x145c8dd41700] DEBUG - Completed after connection close: [192.168.201.249:57692] 206 GET /library/parts/2438/1503616629/file.mp4?autoAdjustQuality=0&hasMDE=1&location=lan&mediaBufferSize=74944 (23 live) TLS 427ms 6963200 bytes (range: bytes=0-) 
Mar 25, 2021 21:43:00.917 [0x145c8dd41700] DEBUG - Auth: authenticated user 65197013 as Wife
Mar 25, 2021 21:43:00.917 [0x145c7d3e9700] DEBUG - Request: [192.168.201.249:57696 (WAN)] GET /library/parts/2438/1503616629/file.mp4?autoAdjustQuality=0&hasMDE=1&location=lan&mediaBufferSize=74944 (23 live) TLS Signed-in Token (Wife) (range: bytes=1346749-) 
Mar 25, 2021 21:43:00.921 [0x145c7d3e9700] DEBUG - Content-Length of /data/Shows/Battlestar Galactica (2003)/Season 2/Battlestar Galactica (2003) - S02E18 - Downloaded.mp4 is 221020361 (of total: 222367110).
Mar 25, 2021 21:43:01.028 [0x145c8c736700] DEBUG - Request: [127.0.0.1:60922 (Loopback)] GET /identity (23 live) Signed-in

I also see a problem with your own SSL cert not being “OK”

Mar 25, 2021 20:44:05.841 [0x145c7d1e8700] WARN - HTTP error requesting GET https://plex.XXXXX.XXX:42300 (60, SSL peer certificate or SSH remote key was not OK) (SSL: no alternative certificate subject name matches target host name 'plex.XXXXX.XXX')

Having a single file, and not a full set, makes debug extremely difficult.

Also need to know about the player but please be advised – I am not an app guy. I am the server-side (OS) guy Linux.

You’re presenting me Docker on Unraid. My docker is limited and I have no experience with how to resolve issues on Unraid so I am really going to be of limited help here in resolving other than pointing out what PMS is reporting.

I hope that’s ok?

20

I updated this morning and let things run their course. Looks like it took about 5 minutes to make the database changes. It seems to be up and running smoothly now, but I’ll keep an eye on it.