Version 0.18.0 always timeout

[mariushosting]

. broker -> redis://redis:6379//

. loader -> celery.loaders.app.AppLoader

. scheduler -> celery.beat.PersistentScheduler

. db -> ./db/celerybeat-schedule

. logfile -> [stderr]@%INFO

. maxinterval -> 5.00 minutes (300s)

2025-02-01 00:16:24,860 INFO success: gunicorn entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)

2025-02-01 00:16:24,861 INFO success: celery entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)

2025-02-01 00:16:24,861 INFO success: celery-beat entered RUNNING state, process has stayed up for > than 1 seconds (startsecs)

[2025-02-01 00:16:24 +0200] [27] [INFO] beat: Starting...

-------------- celery@3d003b236183 v5.4.0 (opalescent)

--- ***** -----

-- ******* ---- Linux-4.4.302+-x86_64-with-glibc2.31 2025-02-01 00:16:24

• *** --- * ---

• ** ---------- [config]

• ** ---------- .> app: yamtrack:0x7f9a0b502850

• ** ---------- .> transport: redis://redis:6379//

• ** ---------- .> results:

• *** --- * --- .> concurrency: 1 (prefork)

-- ******* ---- .> task events: OFF (enable -E to monitor tasks in this worker)

--- ***** -----

-------------- [queues]

            .> celery           exchange=celery(direct) key=celery

[tasks]

. Import from AniList

. Import from Kitsu by user ID

. Import from Kitsu by username

. Import from MyAnimeList

. Import from SIMKL

. Import from TMDB

. Import from Trakt

. Import from Yamtrack

. Reload calendar

[2025-02-01 00:16:24 +0200] [26] [INFO] Connected to redis://redis:6379//

[2025-02-01 00:16:24 +0200] [26] [INFO] celery@3d003b236183 ready.

[2025-02-01 00:17:03 +0200] [25] [CRITICAL] WORKER TIMEOUT (pid:28)

[2025-02-01 00:17:03 +0200] [28] [ERROR] Error handling request (no URI read)

Traceback (most recent call last):

File "/usr/local/lib/python3.11/site-packages/gunicorn/workers/sync.py", line 133, in handle

req = next(parser)

      ^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/parser.py", line 41, in next

self.mesg = self.mesg_class(self.cfg, self.unreader, self.source_addr, self.req_count)

            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 259, in init

super().__init__(cfg, unreader, peer_addr)

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 60, in init

unused = self.parse(self.unreader)

         ^^^^^^^^^^^^^^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 271, in parse

self.get_data(unreader, buf, stop=True)

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 262, in get_data

data = unreader.read()

       ^^^^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/unreader.py", line 36, in read

d = self.chunk()

    ^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/unreader.py", line 63, in chunk

return self.sock.recv(self.mxchunk)

       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/workers/base.py", line 204, in handle_abort

sys.exit(1)

SystemExit: 1

[2025-02-01 00:17:03 +0200] [28] [INFO] Worker exiting (pid: 28)

[2025-02-01 00:17:03 +0200] [63] [INFO] Booting worker with pid: 63

[2025-02-01 00:19:36 +0200] [25] [CRITICAL] WORKER TIMEOUT (pid:63)

[2025-02-01 00:19:36 +0200] [63] [ERROR] Error handling request (no URI read)

Traceback (most recent call last):

File "/usr/local/lib/python3.11/site-packages/gunicorn/workers/sync.py", line 133, in handle

req = next(parser)

      ^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/parser.py", line 41, in next

self.mesg = self.mesg_class(self.cfg, self.unreader, self.source_addr, self.req_count)

            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 259, in init

super().__init__(cfg, unreader, peer_addr)

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 60, in init

unused = self.parse(self.unreader)

         ^^^^^^^^^^^^^^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 271, in parse

self.get_data(unreader, buf, stop=True)

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 262, in get_data

data = unreader.read()

       ^^^^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/unreader.py", line 36, in read

d = self.chunk()

    ^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/http/unreader.py", line 63, in chunk

return self.sock.recv(self.mxchunk)

       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^

File "/usr/local/lib/python3.11/site-packages/gunicorn/workers/base.py", line 204, in handle_abort

sys.exit(1)

SystemExit: 1

[2025-02-01 00:19:36 +0200] [63] [INFO] Worker exiting (pid: 63)

[2025-02-01 00:19:36 +0200] [183] [INFO] Booting worker with pid: 183

[2025-02-01 00:19:37 +0200] [183] [INFO] New user registered: marius at 192.168.48.1

Looks like version 0.18.0 not working anymore. Always get timeout.

[FuzzyGrim]

Did this problem start specifically after upgrading to v0.18.0?

Can you test if after restarting the container, can you access your profile page by visiting: http://URL/login?next=/profile

Can you test to see if it works with a fresh YamTrack container with version 0.18.0 without any existing data?

I see a similar issue being discussed in the Gunicorn repository (benoitc/gunicorn#3207), so it may be a Gunicorn-related issue.

What web browser are you using? In the gunicorn issue some have reported problems with chrome.

[mariushosting]

No issue on version 17.3 but so much lag. And yes I tested it on chrome but Firefox as well.

Version 18 go into timeout on Firefox too.
I'm using the compose here: https://mariushosting.com/how-to-install-yamtrack-on-your-synology-nas/ now adapted to version 0.17.3

[ch-world]

Same here. Fresh install with clean database. Using docker-compose.yml from the repo.

[FuzzyGrim]

Do you get those error logs before trying to access the application or after? Are you connecting through a reverse proxy?

[ch-world]

The errors happen when navigating in the application especially when saving. The application hangs and after a few seconds browser shows "Internal Server Error". Connection is directly via the exposed port.

Host OS is Unraid 7.0. I was able to reproduce on 2 different Unraid systems. On WSL2 with Ubuntu I'm not receiving the errors.

[FuzzyGrim]

Can you try providing your own API keys for the service you are using TMDB (TV shows and movies) / MAL (anime and manga) / IGDB (video games)? It's possible that the app slows down because the API keys provided by default are being rate limited, and the app timeouts after waiting 30 seconds.

[ch-world]

Tried with own TMDB API key but still the same. I enabled debug and it looks like the timeout is occuring before calling the API.

[2025-02-03 20:18:35 +0000] [636] [DEBUG] https://api.themoviedb.org:443 "GET /3/movie/779302?api_key=MYAPIKEY&language=de&append_to_response=recommendations HTTP/1.1" 200 None
[2025-02-03 20:18:38 +0000] [636] [INFO] Being Bridget Jones saved successfully.
[2025-02-03 20:19:27 +0000] [17] [CRITICAL] WORKER TIMEOUT (pid:636)
[2025-02-03 20:19:27 +0000] [636] [ERROR] Error handling request (no URI read)
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/gunicorn/workers/sync.py", line 133, in handle
    req = next(parser)
          ^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/gunicorn/http/parser.py", line 41, in __next__
    self.mesg = self.mesg_class(self.cfg, self.unreader, self.source_addr, self.req_count)
                ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 259, in __init__
    super().__init__(cfg, unreader, peer_addr)
  File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 60, in __init__
    unused = self.parse(self.unreader)
             ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 271, in parse
    self.get_data(unreader, buf, stop=True)
  File "/usr/local/lib/python3.11/site-packages/gunicorn/http/message.py", line 262, in get_data
    data = unreader.read()
           ^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/gunicorn/http/unreader.py", line 36, in read
    d = self.chunk()
        ^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/gunicorn/http/unreader.py", line 63, in chunk
    return self.sock.recv(self.mxchunk)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/gunicorn/workers/base.py", line 204, in handle_abort
    sys.exit(1)
SystemExit: 1
[2025-02-03 20:19:27 +0000] [636] [INFO] Worker exiting (pid: 636)
[2025-02-03 20:19:27 +0000] [714] [INFO] Booting worker with pid: 714
[2025-02-03 20:19:27 +0000] [714] [DEBUG] Starting new HTTPS connection (1): api.themoviedb.org:443
[2025-02-03 20:19:27 +0000] [714] [DEBUG] https://api.themoviedb.org:443 "GET /3/search/tv?api_key=MYAPIKEY&language=de&query=greys+anatomie HTTP/1.1" 200 None

-> I marked a movie successfully as watched and afterswards I started a search for a TV series. This time the worker exited and the timeout occured.

[FuzzyGrim]

Did this problem also started to happen to you after v0.18.0? I have created a pr for this problem, could you try this image in your docker-compose.yml?

image: ghcr.io/fuzzygrim/yamtrack:pr-329

[ch-world]

With this image I wasn't able to reproduce the error so far by searching and adding movies and tv series. However I was able to produce an endless loop as I didn't provide my own key for IGDB. Those errors appear every second and web app is no longer responding.

[2025-02-04 18:44:31 +0000] [33] [DEBUG] https://api.igdb.com:443 "POST /v4/games HTTP/1.1" 401 434
[2025-02-04 18:44:31 +0000] [33] [WARNING] Invalid IGDB access token, refreshing
2025/02/04 18:44:31 [warn] 21#21: *2 upstream server temporarily disabled while reading response header from upstream, client: 192.168.178.21, server: _, request: "POST /progress_edit HTTP/1.1", upstream: "http://127.0.0.1:8001/progress_edit", host: "cubi.local:8017", referrer: "http://cubi.local:8017/"
2025/02/04 18:44:31 [error] 21#21: *2 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 192.168.178.21, server: _, request: "POST /progress_edit HTTP/1.1", upstream: "http://127.0.0.1:8001/progress_edit", host: "cubi.local:8017", referrer: "http://cubi.local:8017/"
192.168.178.21 - - [04/Feb/2025:18:44:31 +0000] "POST /progress_edit HTTP/1.1" 504 569 "http://cubi.local:8017/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/132.0.0.0 Safari/537.36"
[2025-02-04 18:44:31 +0000] [33] [DEBUG] https://id.twitch.tv:443 "POST /oauth2/token HTTP/1.1" 200 93

[FuzzyGrim]

Ok, I have merged the other image to dev and made a commit on the IGDB issue.