PAL dies without connection to Plex

[rg9400]

I know this feature was supposed to add resiliency if Plex is down - https://github.com/RemiRigal/Plex-Auto-Languages/pull/40

But it seems like either there is a code bug or it still dies after a certain number of attempts:

last Thursday at 12:30:08 PM 2022-09-01 12:30:08,774 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:30:13 PM 2022-09-01 12:30:13,785 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:30:18 PM 2022-09-01 12:30:18,792 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:30:23 PM 2022-09-01 12:30:23,805 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:30:28 PM 2022-09-01 12:30:28,814 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:30:33 PM 2022-09-01 12:30:33,868 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:30:38 PM 2022-09-01 12:30:38,908 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:30:43 PM 2022-09-01 12:30:43,912 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:30:48 PM 2022-09-01 12:30:48,918 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:30:53 PM 2022-09-01 12:30:53,921 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:30:58 PM 2022-09-01 12:30:58,929 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:31:03 PM 2022-09-01 12:31:03,931 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:31:08 PM 2022-09-01 12:31:08,940 [WARNING] ConnectionError: Unable to connect to Plex server, retrying...
last Thursday at 12:31:13 PM Traceback (most recent call last):
last Thursday at 12:31:13 PM   File "main.py", line 110, in <module>
last Thursday at 12:31:13 PM     plex_auto_languages.start()
last Thursday at 12:31:13 PM   File "main.py", line 68, in start
last Thursday at 12:31:13 PM     self.init()
last Thursday at 12:31:13 PM   File "main.py", line 45, in init
last Thursday at 12:31:13 PM     self.plex = PlexServer(self.config.get("plex.url"), self.config.get("plex.token"), self.notifier, self.config)
last Thursday at 12:31:13 PM   File "/app/plex_auto_languages/plex_server.py", line 98, in __init__
last Thursday at 12:31:13 PM     super().__init__(url, token)
last Thursday at 12:31:13 PM   File "/app/plex_auto_languages/plex_server.py", line 30, in __init__
last Thursday at 12:31:13 PM     self._plex = self._get_server(url, token)
last Thursday at 12:31:13 PM   File "/app/plex_auto_languages/plex_server.py", line 126, in _get_server
last Thursday at 12:31:13 PM     return BasePlexServer(url, token)
last Thursday at 12:31:13 PM   File "/usr/local/lib/python3.8/site-packages/plexapi/server.py", line 117, in __init__
last Thursday at 12:31:13 PM     data = self.query(self.key, timeout=self._timeout)
last Thursday at 12:31:13 PM   File "/usr/local/lib/python3.8/site-packages/plexapi/server.py", line 682, in query
last Thursday at 12:31:13 PM     raise BadRequest(message)
last Thursday at 12:31:13 PM plexapi.exceptions.BadRequest: (503) service_unavailable; http://plex:32400/ <?xml version="1.0" encoding="utf-8"?><Response code="503" title="Maintenance" status="PMS is currently running startup maintenance tasks."/>
yesterday at 4:30:03 AM Exception in thread Thread-2:
yesterday at 4:30:03 AM Traceback (most recent call last):
yesterday at 4:30:03 AM   File "/usr/local/lib/python3.8/threading.py", line 932, in _bootstrap_inner
yesterday at 4:30:03 AM     self.run()
yesterday at 4:30:03 AM   File "/app/plex_auto_languages/utils/scheduler.py", line 22, in run
yesterday at 4:30:03 AM     schedule.run_pending()
yesterday at 4:30:03 AM   File "/usr/local/lib/python3.8/site-packages/schedule/__init__.py", line 780, in run_pending
yesterday at 4:30:03 AM     default_scheduler.run_pending()
yesterday at 4:30:03 AM   File "/usr/local/lib/python3.8/site-packages/schedule/__init__.py", line 100, in run_pending
yesterday at 4:30:03 AM     self._run_job(job)
yesterday at 4:30:03 AM   File "/usr/local/lib/python3.8/site-packages/schedule/__init__.py", line 172, in _run_job
yesterday at 4:30:03 AM     ret = job.run()
yesterday at 4:30:03 AM   File "/usr/local/lib/python3.8/site-packages/schedule/__init__.py", line 661, in run
yesterday at 4:30:03 AM     ret = self.job_func()
yesterday at 4:30:03 AM   File "main.py", line 96, in scheduler_callback
yesterday at 4:30:03 AM     if self.plex or not self.plex.is_alive:
yesterday at 4:30:03 AM AttributeError: 'NoneType' object has no attribute 'is_alive'

[RemiRigal]

There are actually two separate errors in your logs:

• PAL was not catching plexapi.exceptions.BadRequest during connection attempts, thus stopping it from attempting again. This is not the desired behavior, it has been fixed in 198d1f2cc524ff31ead61d9209d53dcd32c34b4f.
• The scheduler task (scheduled at 4:30 AM in your case) expected an active connection to the Plex server, which is not always the case. This issue has been fixed by 478a21b9bdce18636c48cd98b2c19a8503a9ae41.

Try the latest version and let me know if you still encounter the issue !

[tronyx]

Not sure how I can check what version I'm on with Docker, but I experienced this today when I updated my container and PAL never reconnected until I restarted the container. I have debug on, but I don't see much. Also, not sure why, but the container logs are really wonky for me, in terms of how they display, unless I use JQ.

[seanecoffey]

I just had a similar problem when my plex server crashed for ~2 minutes. After restarting the plex docker (working fine), i noticed the PAL CPU usage was going a bit crazy, seemed to be having some recursive errors. Logs: https://gist.github.com/seanecoffey/b71e8e23e8f411cd3c69c69aa689ba5a