truenas / charts

TrueNAS SCALE Apps Catalogs & Charts
BSD 3-Clause "New" or "Revised" License
311 stars 296 forks source link

Plex app won't start on scale... sometimes. #2956

Closed adude00 closed 4 days ago

adude00 commented 6 days ago

Sometimes (20-30% of the times?) Plex container/pod (unsure of the correct nomenclature here) won't start. Logs shows the container is unable to find the Plex executable and then gets stuck in an infinite loop.

Here is an extract of the logs when it's not starting.

2024-11-23T14:49:40.928783420+01:00 [s6-init] making user provided files available at /var/run/s6/etc...exited 0.
2024-11-23T14:49:42.099333672+01:00 [s6-init] ensuring user provided files have correct perms...exited 0.
2024-11-23T14:49:42.100417673+01:00 [fix-attrs.d] applying ownership & permissions fixes...
2024-11-23T14:49:42.105498552+01:00 [fix-attrs.d] done.
2024-11-23T14:49:42.105893535+01:00 [cont-init.d] executing container initialization scripts...
2024-11-23T14:49:42.110326807+01:00 [cont-init.d] 40-plex-first-run: executing... 
2024-11-23T14:49:44.077377439+01:00 Plex Media Server first run setup complete
2024-11-23T14:49:44.092417956+01:00 [cont-init.d] 40-plex-first-run: exited 0.
2024-11-23T14:49:44.092463857+01:00 [cont-init.d] 45-plex-hw-transcode-and-connected-tuner: executing... 
2024-11-23T14:49:44.104309273+01:00 [cont-init.d] 45-plex-hw-transcode-and-connected-tuner: exited 0.
2024-11-23T14:49:44.109094256+01:00 [cont-init.d] 50-plex-update: executing... 
2024-11-23T14:49:44.385560355+01:00 Could not get update version
2024-11-23T14:49:44.388079666+01:00 [cont-init.d] 50-plex-update: exited 0.
2024-11-23T14:49:44.389507570+01:00 [cont-init.d] done.
2024-11-23T14:49:44.391461076+01:00 [services.d] starting services
2024-11-23T14:49:44.410147809+01:00 Starting Plex Media Server.
2024-11-23T14:49:44.424255572+01:00 [services.d] done.
2024-11-23T14:49:44.426220281+01:00 s6-applyuidgid: fatal: unable to exec /usr/lib/plexmediaserver/Plex Media Server: No such file or directory
2024-11-23T14:49:44.431187526+01:00 Stopping Plex Media Server.
2024-11-23T14:49:44.455582529+01:00 kill: usage: kill [-s sigspec | -n signum | -sigspec] pid | jobspec ... or kill -l [sigspec]
2024-11-23T14:49:49.481755169+01:00 Starting Plex Media Server.
2024-11-23T14:49:49.521346921+01:00 s6-applyuidgid: fatal: unable to exec /usr/lib/plexmediaserver/Plex Media Server: No such file or directory
2024-11-23T14:49:49.533992291+01:00 Stopping Plex Media Server.
2024-11-23T14:49:49.557819180+01:00 kill: usage: kill [-s sigspec | -n signum | -sigspec] pid | jobspec ... or kill -l [sigspec]
2024-11-23T14:49:54.573270066+01:00 Starting Plex Media Server.
2024-11-23T14:49:54.578598386+01:00 s6-applyuidgid: fatal: unable to exec /usr/lib/plexmediaserver/Plex Media Server: No such file or directory
2024-11-23T14:49:54.581658739+01:00 Stopping Plex Media Server.
2024-11-23T14:49:54.587561086+01:00 kill: usage: kill [-s sigspec | -n signum | -sigspec] pid | jobspec ... or kill -l [sigspec]
2024-11-23T14:49:59.595460365+01:00 Starting Plex Media Server.
2024-11-23T14:49:59.598832740+01:00 s6-applyuidgid: fatal: unable to exec /usr/lib/plexmediaserver/Plex Media Server: No such file or directory
2024-11-23T14:49:59.601740787+01:00 Stopping Plex Media Server.
2024-11-23T14:49:59.605082465+01:00 kill: usage: kill [-s sigspec | -n signum | -sigspec] pid | jobspec ... or kill -l [sigspec]

This goes on and on and on.

When it does starts correctly it looks like it's downloading it from the internet (full logs here)

2024-11-23T15:05:18.121781060+01:00 [s6-init] making user provided files available at /var/run/s6/etc...exited 0.
2024-11-23T15:05:19.745382424+01:00 [s6-init] ensuring user provided files have correct perms...exited 0.
2024-11-23T15:05:19.746174696+01:00 [fix-attrs.d] applying ownership & permissions fixes...
2024-11-23T15:05:19.746984685+01:00 [fix-attrs.d] done.
2024-11-23T15:05:19.747500934+01:00 [cont-init.d] executing container initialization scripts...
2024-11-23T15:05:19.748325145+01:00 [cont-init.d] 40-plex-first-run: executing... 
2024-11-23T15:05:20.623151932+01:00 Plex Media Server first run setup complete
2024-11-23T15:05:20.623639965+01:00 [cont-init.d] 40-plex-first-run: exited 0.
2024-11-23T15:05:20.624386481+01:00 [cont-init.d] 45-plex-hw-transcode-and-connected-tuner: executing... 
2024-11-23T15:05:20.640629002+01:00 [cont-init.d] 45-plex-hw-transcode-and-connected-tuner: exited 0.
2024-11-23T15:05:20.641328111+01:00 [cont-init.d] 50-plex-update: executing... 
2024-11-23T15:05:20.959254634+01:00 Attempting to upgrade to: 1.41.2.9200-c6bbc1b53
2024-11-23T15:05:20.966431088+01:00   % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
2024-11-23T15:05:20.966482383+01:00                                  Dload  Upload   Total   Spent    Left  Speed
2024-11-23T15:05:21.109387456+01:00 ^M  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0^M  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
2024-11-23T15:05:22.554057186+01:00 ^M 16 77.7M   16 13.1M    0     0  20.9M      0  0:00:03 --:--:--  0:00:03 20.9M^M100 77.7M  100 77.7M    0     0  49.0M      0  0:00:01  0:00:01 --:--:-- 67.2M
2024-11-23T15:05:23.391148665+01:00 Selecting previously unselected package plexmediaserver.
2024-11-23T15:05:23.448906373+01:00 (Reading database ... 7274 files and directories currently installed.)
2024-11-23T15:05:23.449443578+01:00 Preparing to unpack /tmp/plexmediaserver.deb ...
2024-11-23T15:05:23.464211119+01:00 PlexMediaServer install: Pre-installation Validation.
2024-11-23T15:05:23.473445981+01:00 PlexMediaServer install: Custom environment detected.  Skipping preinstallation validation.
2024-11-23T15:05:23.477720162+01:00 Unpacking plexmediaserver (1.41.2.9200-c6bbc1b53) ...
2024-11-23T15:05:31.307628827+01:00 Setting up plexmediaserver (1.41.2.9200-c6bbc1b53) ...
2024-11-23T15:05:31.387294580+01:00 PlexMediaServer install: Custom environment detected.  Skipping postinstallation tasks. Continuing.
2024-11-23T15:05:33.034383485+01:00 [cont-init.d] 50-plex-update: exited 0.
2024-11-23T15:05:33.035113967+01:00 [cont-init.d] done.
2024-11-23T15:05:33.035856714+01:00 [services.d] starting services
2024-11-23T15:05:33.056779613+01:00 Starting Plex Media Server.
2024-11-23T15:05:33.061479107+01:00 [services.d] done.
2024-11-23T15:05:46.059771014+01:00 Critical: libusb_init failed

Again it's happening not all the time and I haven't found any reliable steps to reproduce it.

I turn my NAS off after using it, when I turn it on again, maybe one or three days later, most of the times Plex starts fine but sometimes it won't.

Restarting the app fixes it, all the time.

I use a CLI script that first run a

ssh root@opti midclt call chart.release.scale plex \'{\"replica_count\": 0}\' then a ssh root@opti midclt call chart.release.scale plex \'{\"replica_count\": 1}\'

To fix it from my home automation.

I noticed that if I wait long enough (20, maybe 30 minutes?) the container eventually gets restarted, maybe after it reaches some kind of timeout?

I'm running Dragonfish-24.04.2.5. It has been this way forever so I'm not sure is related to TrueNAS version.

I notice that when it does not work it looks like it's not able to get the updated version. Is that a network error? If so, why would it need to always download the new version? Can't it use the version that it's already downloaded locally and only upgrade it when an actual upgrade is performed in TrueNAS GUI?

As a workaround, is there any way to reduce this timeout?

stavros-k commented 4 days ago

I think plex pulls down a zip when it starts and unpacks it. There isn't anything we can do there.

What I can suggest is upgrading to 24.10 which uses docker instead of kubernetes. Not sure if the issue lies there, but you can try.

Remember to check truenas release notes before upgrading.

Considering kubernetes apps system is deprecated, I'm going to close this now.