"Server Unavailable" for ~30 seconds, then comes back

[thephilipjones]

Server Version#:1.40.4.8679-424562606
Player Version#: 8.38.1 (8966) for example

Plex is running on a tteck Proxmox LXC with access to share up to all 8 cores of the i7 EliteDesk host and 4GB RAM. It’s my favorite way yet to run PMS, of all the 8 varieties I’ve run over the past 15 years

Unfortunately playback is frequently interrupted about 1-3 times per movie whether viewing on LAN Apple TVs, or a cross-town Fire Stick. The app reports some variety of “server unavailable” and/or “lost connection”, including browsing any of my server’s libraries.

Then it comes back, about 30 seconds later. “Browse to a different library or restart the app and it should come back now”

I’m running Netdata on it and see a CPU spike but I haven’t really figured out how to debug or what to look for in logs.

I do have Tautulli monitoring as well (but due to a separate issue the text it says is always just “Tautulli Notification”) and I do see one from the server that seems to be associated with “we’re back”.

I apt-get upgraded to 1.40.5.8897-e5987a19d just now so we’ll see if that helps but this has been happening a bit more often over the past several months.

[ChuckPa]

going to need server DEBUG logs which you captured (downloaded) right after this happens so we can see what happened.

[thephilipjones]

Great, thanks. Finally able to capture the logs right after it happened. Full Zip file ok?
Plex Media Server Logs_2024-10-27_17-24-23.zip (5.1 MB)

[ChuckPa]

I’ve made one pass over your logs.

I’ve not yet found the 30-second gap.

What I did find is this:

024 17:15:49.222 [135273183976248] DEBUG - [Req#237d60c4] Statistics: (E1D410F5-178A-4BEA-AEC2-69B5FB4BB9FA) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 7258287
Oct 27, 2024 17:15:59.942 [135275955678008] DEBUG - CERT: incomplete TLS handshake from [::ffff:10.0.10.10]:38862: stream truncated

To keep things clean and avoid connection issues (maybe the cause of the burp?) , I recommend you turn off “IPv6” support in Settings - Server - Network because you’re running on an IPv4 LAN. It’s not handling the SSL handshake correctly. (I don’t trust it)

Might you know the approximate time the lapse occurred ?

[thephilipjones]

Thanks for the quick response! This time the outage lasted longer, it appears to be 8 minutes from 17:14–17:22. Here are a couple screenshots of Netdata, looking like the RAM is just dwindling to 0, while CPU spikes and then causes non-responsiveness.

During the outage I was unable to load the local plex.mydomain.app page, and SSH to the VM timed out. Proxmox was showing the CPU go from single digits to ~80% consistent.

I’ll turn off IPv6 support. Anything else unusual in that :14-:22 timeframe?

[ChuckPa]

DEBUG
LOGS???

Please

[thephilipjones]

Sorry I must have missed something. Is there another way to get the Debug Logs? I have had Debug on, Verbose off, at least since starting this thread.

[ChuckPa]

The “debug” logs…

Just like what you gave me the first time.
I’d like to catch PMS “red handed” if I can.

you can always stop PMS,
get into the terminal/shell window,
cd down into where Plex Media Server is,
sudo tar czf /tmp/PlexLogs.tar.gz ./Logs

This puts PlexLogs.tar.gz in /tmp and captures the entire “Logs” directory
(Just as if you pulled logs normally from PMS itself)

[thephilipjones]

Ok I see. Just clarifying there was not a second outage today, I was referring to the same instance and set of logs. Here’s the whole log dump anyway per your guidance.
PlexLogs.tar.gz (7.1 MB)

[ChuckPa]

This is the bottom of Plex Media Server.4.log

Oct 27, 2024 17:15:48.857 [135275953568568] DEBUG - Removed transcode data consumer, active count 1 => 0
Oct 27, 2024 17:15:48.871 [135273183976248] DEBUG - [Req#237d60c4] Play progress on 553640 'Casper' - got played 912552 ms by account 7258287!
Oct 27, 2024 17:15:48.876 [135273183976248] DEBUG - [Req#237d60c4] [Now] User is Rmspark (ID: 7258287)
Oct 27, 2024 17:15:48.886 [135273183976248] DEBUG - [Req#237d60c4] [Now] Device is tvOS (Apple TV).
Oct 27, 2024 17:15:48.889 [135273183976248] DEBUG - [Req#237d60c4] [Now] Profile is tvOS
Oct 27, 2024 17:15:48.889 [135273183976248] DEBUG - [Req#237d60c4] [Now] Updated play state for /library/metadata/553640.
Oct 27, 2024 17:15:48.948 [135273214552888] DEBUG - [Req#237d60b8] Client [2e651718c33454d2-com-plexapp-android] reporting timeline state playing, progress of 3531091/6008419ms for guid=plex://movie/5d77683261141d001fb14df9, playbackTime=3531170ms ratingKey=553640 url=, key=/library/metadata/553640, containerKey=, metadataId=553640, source=
Oct 27, 2024 17:15:49.033 [135273183976248] DEBUG - [Req#237d60c4] It took 140.000000 ms to retrieve 1 items.
Oct 27, 2024 17:15:49.214 [135273188195128] DEBUG - Request: [127.0.0.1:37362 (Loopback)] PUT /video/:/transcode/session/FC8BBDB1-5D1E-41C3-9699-6E506923B4E9/4bf95fe3-8483-4d02-a44f-93397dc6ab1f/progress?progress=17.7&size=-22&remaining=-1&vdec_packets=25519&vdec_hw_ok=25509&speed=0.0&vdec_hw_status=1 (14 live) #237d60d1 Signed-in Token (thephilipjones) (range: bytes=0-) 
Oct 27, 2024 17:15:49.220 [135273214552888] DEBUG - [Req#237d60b8] Play progress on 553640 'Casper' - got played 3531091 ms by account 28282721!
Oct 27, 2024 17:15:49.222 [135273183976248] DEBUG - [Req#237d60c4] Statistics: (E1D410F5-178A-4BEA-AEC2-69B5FB4BB9FA) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 7258287
Oct 27, 2024 17:15:59.942 [135275955678008] DEBUG - CERT: incomplete TLS handshake from [::ffff:10.0.10.10]:38862: stream truncated

Now look at the top of the next rollover Plex Media Server.3.log

Oct 27, 2024 17:23:37.115 [132053299759928] INFO - Plex Media Server v1.41.0.8994-f2c27da23 - Ubuntu PC x86_64 - build: linux-x86_64 debian - GMT -04:00
Oct 27, 2024 17:23:37.116 [132053299759928] INFO - Linux version: 20.04.6 LTS (Focal Fossa), language: en-US
Oct 27, 2024 17:23:37.116 [132053299759928] INFO - Processor: 8-core Intel(R) Core(TM) i7-9700T CPU @ 2.00GHz
Oct 27, 2024 17:23:37.116 [132053299759928] INFO - Compiler is - Clang 11.0.1 (https://plex.tv 9b997da8e5b47bdb4a9425b3a3b290be393b4b1f)
Oct 27, 2024 17:23:37.116 [132053299759928] INFO - /usr/lib/plexmediaserver/Plex Media Server
Oct 27, 2024 17:23:37.116 [132053302315664] DEBUG - BPQ: [Idle] -> [Starting]
Oct 27, 2024 17:23:37.117 [132053302315664] DEBUG - FeatureManager: Using cached data for features list
Oct 27, 2024 17:23:37.121 [132053302315664] DEBUG - MyPlex: mapping state set to 'Unknown'.
Oct 27, 2024 17:23:37.121 [132053302315664] DEBUG - Relay: read 70 cached entries from hosts file
Oct 27, 2024 17:23:37.122 [132053302315664] DEBUG - Opening 20 database sessions to library (com.plexapp.plugins.library), SQLite 3.39.4, threadsafe=1
Oct 27, 2024 17:23:37.124 [132053302315664] INFO - SQLITE3:0x80000001, 283, recovered 166 frames from WAL file /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Plug-in Support/Databases/com.plexapp.plugins.library.db-wal

Your PMS server was fully down. Abruptly down at that.

Did ProxMox register any LXC crashes?
Was there a reboot?
PMS came back up , recovered, and continued about on it’s merry way.

I’m also using the TTECK LXC on Proxmox and don’t see this behavior at all.

[thephilipjones]

Abruptly down… and then on its merry way - exactly right.
uptime reports 16 days so I don’t think a reboot?

I’ll have to figure out how to look at Proxmox LXC crashes unless you could help there too.

[ChuckPa]

I don’t know enough about ProxMox to go that deep

I needed a tutorial / how-to to install & setup.
( I did it because all of you who run ProxMox. lol )

[thephilipjones]

Haha thanks, I’ll poke around. Either way, does it seem like it’s “not a Plex issue” or whether I should be looking at the underlying hardware / host?

[ChuckPa]

I’m very inclined to say “host” because there was an abrupt stop
–AND–
the restart delay was 30 seconds.

Container restarts (restart due to app failure) usually are 2-3 seconds after failure in my experience

I might be wrong here. I do not know what the tteck health check interval is.
It might only be checking the LXC every 30 seconds.

[thephilipjones]

Thanks. Found some journalctl indicating that oom-killer on the host did indeed take out PMS.
systemd invoked oom-killer: gfp_mask=0x100cca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0

[  pid  ]   uid  tgid total_vm      rss pgtables_bytes swapents oom_score_adj name
...
[2835926]   998 2835926   721602   588903  5812224        0             0 Plex Media Serv
...

Memory cgroup out of memory: Killed process 2835926 (Plex Media Serv) total-vm:2886408kB, anon-rss:2355484kB

Guess I’m taking this to the Proxmox side unless any other thoughts.

[ChuckPa]

If I read that right, you have just over 2GB of memory showing there.

Did you declare the max memory quota on the VM?

My VM is running with 4GB of RAM.

If you’re running tteck defaults, then definitely go ask.

[thephilipjones]

I started it with tteck and modified the LXC (currently idle, fresh reboot):

4GB as well for Plex, out of 32GB on the host. 28GB of which is theoretical allocated max across VM/LXCs.

[ChuckPa]

Hmmm

EDIT: If my math is right, it was using 5GB of RAM

expr 2886408 + 2355484
5241892

Increase the max memory to 6G and keep an eye on it.

I prefer when NAS systems have 8GB of RAM. This type of event is why

[thephilipjones]

I do want to be cautious with Proxmox host headroom with ZFS and all, but that sounds as good as any to try. Thanks.