RemiRigal / Plex-Auto-Languages

Automated language selection for Plex TV Shows !
MIT License
428 stars 16 forks source link

Issue at Startup #41

Closed CardcaptorRLH85 closed 2 years ago

CardcaptorRLH85 commented 2 years ago

When I initially set this program up, it was working perfectly but now, it's giving me an error. Here's the debug log.

debug log ``` 2022-05-15 12:34:18,172 [INFO] Trying to restore the connection to the Plex server... 2022-05-15 12:34:18,681 [INFO] Successfully connected as user 'CardcaptorRLH85' (id: 1) 2022-05-15 12:34:18,682 [DEBUG] [Cache] Loading server cache from file 2022-05-15 12:34:18,687 [INFO] Starting alert listener 2022-05-15 12:34:18,717 [WARNING] Alert listener had an unexpected error 2022-05-15 12:34:19,689 [DEBUG] [Cache] Saving server cache to file 2022-05-15 12:34:19,698 [INFO] Trying to restore the connection to the Plex server... 2022-05-15 12:34:20,275 [INFO] Successfully connected as user 'CardcaptorRLH85' (id: 1) 2022-05-15 12:34:20,276 [DEBUG] [Cache] Loading server cache from file 2022-05-15 12:34:20,284 [INFO] Starting alert listener 2022-05-15 12:34:20,335 [WARNING] Alert listener had an unexpected error 2022-05-15 12:34:21,285 [DEBUG] [Cache] Saving server cache to file 2022-05-15 12:34:21,295 [INFO] Trying to restore the connection to the Plex server... ```

This continues for hundreds of lines.

Here's my docker-compose for this container.

docker-compose ``` ... plexautolanguages: image: remirigal/plex-auto-languages:latest container_name: Plex-Auto-Languages environment: - TZ=America/Detroit volumes: - /volume1/docker/Plex-Auto-Languages:/config depends_on: - plex restart: unless-stopped ... ```

Finally, here's a redacted version of my config.yaml.

config.yaml ``` plexautolanguages: # Update language for the entire show or only for the current season # Accepted values: # - show (default) # - season update_level: "show" # Update all episodes of the show/season or only the next ones # Accepted values: # - all (default) # - next update_strategy: "all" # Whether or not playing a file should trigger a language update, defaults to 'true' trigger_on_play: true # Whether or not navigating the Plex library should trigger a language update, defaults to 'false' # Set this to 'true' only if you want to perform changes whenever the default track of an episode is updated, even when the episode is not played. # Setting this parameter to 'true' can result in higher resource usage. trigger_on_activity: false # Plex configuration plex: # A valid Plex URL (required) url: "" # A valid Plex Token (required) token: "" scheduler: # Whether of not to enable the scheduler, defaults to 'true' # The scheduler will perform a deeper analysis of all recently played TV Shows enable: true # The time at which the scheduler start its task with the format 'HH:MM', defaults to '02:00' schedule_time: "04:30" notifications: # Whether of not to enable the notifications through Apprise, defaults to 'false' # A notification is sent whenever a language change is performed enable: false # An array of Apprise configurations, see Apprise docs for more information: https://github.com/caronc/apprise apprise_configs: [] # Whether or not to enable the debug mode, defaults to 'false' # Enabling debug mode will significantly increase the number of output logs debug: true ```

I have a registered domain name that I host all of my local services on in the form . Since the logs show PAL connecting to my Plex server as me, I don't think this is the problem. Also, I specifically turned debug on for diagnosing this issue but it doesn't seem to have added any detail about what the unexpected error was.

CardcaptorRLH85 commented 2 years ago

I've updated my config file to the most recent version with all of the variables set as default and that hasn't helped.

My current file follows.

config.yaml ``` plexautolanguages: # Update language for the entire show or only for the current season # Accepted values: # - show (default) # - season update_level: "show" # Update all episodes of the show/season or only the next ones # Accepted values: # - all (default) # - next update_strategy: "all" # Whether or not playing a file should trigger a language update, defaults to 'true' trigger_on_play: true # Whether or not scanning the library for new files should trigger a language update, defaults to 'true' # A newly added episode will be updated based on the most recently watched episode, or the first episode of the show if it has never been watched trigger_on_scan: true # Whether or not navigating the Plex library should trigger a language update, defaults to 'false' # Only the Plex web client and the Plex for Windows app support this feature # Set this to 'true' only if you want to perform changes whenever the default track of an episode is updated, even when the episode is not played. # Setting this parameter to 'true' can result in higher resource usage. trigger_on_activity: false # Whether or not to refresh the cached library whenever the Plex server scans its own library, defaults to 'true' # Disabling this parameter will prevent PlexAutoLanguages from detecting updated files for an already existing episode # It is recommended to disable this parameter if you have a large TV Show library (10k+ episodes) refresh_library_on_scan: true # Plex configuration plex: # A valid Plex URL (required) url: "" # A valid Plex Token (required) token: "" scheduler: # Whether of not to enable the scheduler, defaults to 'true' # The scheduler will perform a deeper analysis of all recently played TV Shows enable: true # The time at which the scheduler start its task with the format 'HH:MM', defaults to '02:00' schedule_time: "04:30" notifications: # Whether of not to enable the notifications through Apprise, defaults to 'false' # A notification is sent whenever a language change is performed enable: false # An array of Apprise configurations, see Apprise docs for more information: https://github.com/caronc/apprise apprise_configs: [] # Whether or not to enable the debug mode, defaults to 'false' # Enabling debug mode will significantly increase the number of output logs debug: true ```

I've also edited my original post to collapse the log and config files I included.

CardcaptorRLH85 commented 2 years ago

I've tested with 1.1.3, 1.1.2, 1.1.1, 1.1.0, 1.0.15, and 1.0.0. This issue seems to persist across them all even though I didn't have any issues when I initially installed it on April 24th.

RemiRigal commented 2 years ago

Thank you for all the information you provided, it will greatly help to identify the source of the problem !

Based on the timestamp of your logs, the connection for the alert listener seems to fail immediately (less than 100ms between Starting alert listener and Alert listener had an unexpected error). The alert listener is based on a websocket connection, so my guess would be to check your network configuration first, maybe your reverse proxy is blocking the websocket ? Would it be possible for you to use a more direct Plex URL ?

I have improved the amount of information logged when this error occurs, can you use the docker image remirigal/plex-auto-languages:master and see if the error you get is more informative ? Thanks !

CardcaptorRLH85 commented 2 years ago

Switching my url to http://192.168.50.21:32400 seems to have fixed the problem (the container reports healthy now). However, is the log supposed to just stop after "Starting alert listener"? Is there no verification that it started correctly?

Here's the latest cycle of my log. It includes the last error while I was editing my config file and the first working(?) version after the edit.

Current Log ``` 2022-05-16 13:46:47,798 [INFO] Trying to restore the connection to the Plex server... 2022-05-16 13:46:48,313 [INFO] Successfully connected as user 'CardcaptorRLH85' (id: 1) 2022-05-16 13:46:48,314 [DEBUG] [Cache] Loading server cache from file 2022-05-16 13:46:48,320 [INFO] Starting alert listener 2022-05-16 13:46:48,321 [DEBUG] [Cache] Saving server cache to file 2022-05-16 13:46:48,330 [INFO] Stopping scheduler 2022-05-16 13:46:48,357 [ERROR] Alert listener had an unexpected error 2022-05-16 13:46:48,358 [ERROR] Handshake status 400 Bad Request Traceback (most recent call last): File "/usr/local/lib/python3.8/site-packages/websocket/_app.py", line 327, in run_forever self.sock.connect( File "/usr/local/lib/python3.8/site-packages/websocket/_core.py", line 248, in connect self.handshake_response = handshake(self.sock, url, *addrs, **options) File "/usr/local/lib/python3.8/site-packages/websocket/_handshake.py", line 57, in handshake status, resp = _get_resp_headers(sock) File "/usr/local/lib/python3.8/site-packages/websocket/_handshake.py", line 148, in _get_resp_headers raise WebSocketBadStatusException("Handshake status %d %s", status, status_message, resp_headers) websocket._exceptions.WebSocketBadStatusException: Handshake status 400 Bad Request 2022-05-16 13:47:09,017 [INFO] Parsing config file '/config/config.yaml' 2022-05-16 13:47:09,026 [INFO] The provided configuration has been successfully validated 2022-05-16 13:47:09,026 [DEBUG] Debug mode enabled 2022-05-16 13:47:09,028 [INFO] Starting scheduler 2022-05-16 13:47:09,630 [INFO] Successfully connected as user 'CardcaptorRLH85' (id: 1) 2022-05-16 13:47:09,630 [DEBUG] [Cache] Loading server cache from file 2022-05-16 13:47:09,651 [INFO] Starting alert listener ```

I should be adding a file to my server later today that will need the language switcher. I'll be able to figure out if it's working then.

CardcaptorRLH85 commented 2 years ago

OK, it's definitely working now. The new file was updated properly and the logs reflected that.