meeb / tubesync

Syncs YouTube channels and playlists to a locally hosted media server
GNU Affero General Public License v3.0
1.98k stars 129 forks source link

Worker Timeout - Error handling request /tasks #561

Open gardiol opened 11 hours ago

gardiol commented 11 hours ago

I have been hitting this issue since a long time.

tubesync web gui works fine 1 out of 5 times, the other 4 times instead it wait for some 30 seconds, then bails out with an "internal server error".

My setup is TubeSync containerized with my NGINX reverse proxy on front, directly to the TubeSync (port 4848).

Container log is:

[2024-11-25 11:45:56 +0100] [324] [CRITICAL] WORKER TIMEOUT (pid:364)                                                                                                      11:45:56 [102/654]
[2024-11-25 11:45:56 +0100] [364] [ERROR] Error handling request /tasks                       
Traceback (most recent call last):                                                                                                                                                           
  File "/usr/local/lib/python3.11/dist-packages/gunicorn/workers/sync.py", line 134, in handle 
    self.handle_request(listener, req, client, addr)
  File "/usr/local/lib/python3.11/dist-packages/gunicorn/workers/sync.py", line 177, in handle_request
    respiter = self.wsgi(environ, resp.start_response)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/tubesync/wsgi.py", line 25, in application                                                                                                                                      
    return _application(environ, start_response)                                              
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^                                                                                                                                             
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/wsgi.py", line 133, in __call__                                                                                         
    response = self.get_response(request)                                                     
               ^^^^^^^^^^^^^^^^^^^^^^^^^^                                                     
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/base.py", line 130, in get_response
    response = self._middleware_chain(request)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/exception.py", line 47, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/utils/deprecation.py", line 117, in __call__
    response = response or self.get_response(request)
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/exception.py", line 47, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/utils/deprecation.py", line 117, in __call__
    response = response or self.get_response(request)
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/exception.py", line 47, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/utils/deprecation.py", line 117, in __call__
    response = response or self.get_response(request)
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/exception.py", line 47, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/utils/deprecation.py", line 117, in __call__
    response = response or self.get_response(request)
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/exception.py", line 47, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/utils/deprecation.py", line 117, in __call__
    response = response or self.get_response(request)
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/exception.py", line 47, in inner                                                                       11:45:56 [55/654]
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/utils/deprecation.py", line 117, in __call__
    response = response or self.get_response(request)
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/exception.py", line 47, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/utils/deprecation.py", line 117, in __call__
    response = response or self.get_response(request)
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/exception.py", line 47, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/whitenoise/middleware.py", line 123, in __call__
    return self.get_response(request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/exception.py", line 47, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/app/common/middleware.py", line 15, in __call__
    response = self.get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/exception.py", line 47, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/utils/deprecation.py", line 117, in __call__
    response = response or self.get_response(request)
                           ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/exception.py", line 47, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/core/handlers/base.py", line 181, in _get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/views/generic/base.py", line 70, in view
    return self.dispatch(request, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/sync/views.py", line 780, in dispatch
    return super().dispatch(request, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/views/generic/base.py", line 98, in dispatch
    return handler(request, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/views/generic/list.py", line 157, in get
    context = self.get_context_data()                                                                                                                                        11:47:13 [9/654]
              ^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/sync/views.py", line 794, in get_context_data
    obj, url = map_task_to_instance(task)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/sync/tasks.py", line 81, in map_task_to_instance
    instance = model.objects.get(pk=instance_uuid)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/db/models/manager.py", line 85, in manager_method
    return getattr(self.get_queryset(), name)(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/db/models/query.py", line 431, in get
    num = len(clone)
          ^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/db/models/query.py", line 262, in __len__
    self._fetch_all()
  File "/usr/local/lib/python3.11/dist-packages/django/db/models/query.py", line 1324, in _fetch_all
    self._result_cache = list(self._iterable_class(self))
                         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/db/models/query.py", line 51, in __iter__
    results = compiler.execute_sql(chunked_fetch=self.chunked_fetch, chunk_size=self.chunk_size)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/db/models/sql/compiler.py", line 1175, in execute_sql
    cursor.execute(sql, params)
  File "/usr/local/lib/python3.11/dist-packages/django/db/backends/utils.py", line 98, in execute
    return super().execute(sql, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/db/backends/utils.py", line 66, in execute
    return self._execute_with_wrappers(sql, params, many=False, executor=self._execute)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/db/backends/utils.py", line 75, in _execute_with_wrappers
    return executor(sql, params, many, context) 
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 
  File "/usr/local/lib/python3.11/dist-packages/django/db/backends/utils.py", line 84, in _execute
    return self.cursor.execute(sql, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/django/db/backends/sqlite3/base.py", line 423, in execute
    return Database.Cursor.execute(self, query, params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/gunicorn/workers/base.py", line 204, in handle_abort
    sys.exit(1)
SystemExit: 1
10.89.0.6 - - [25/Nov/2024:11:45:56 +0100] "GET /tasks HTTP/1.1" 500 141 "-" "Mozilla/5.0 (X11; Linux x86_64; rv:132.0) Gecko/20100101 Firefox/132.0"
[2024-11-25 11:45:56 +0100] [364] [INFO] Worker exiting (pid: 364)
[2024-11-25 11:45:57 +0100] [374] [INFO] Booting worker with pid: 374

It seems that when the tasks page loads, it's always downloading a specific video from a specific channel. This video has been downloading for days now.

Restarting the container will temporarily fix the issue, but soon it's back.

On container logs, i have nothing else than what copied above.

It's not a resource issue, as both the container and the host are not overloaded, RAM is plentiful and so other resources. There is load at all.

the NGINX in front shows no issues at all, no errors., All reuqests are passed down to TubeSync and the timeout come from Tubesync itself, it seems.

Edit: i have 1284 tasks queued, i can see tasks queued since weeks there...

meeb commented 7 hours ago

Weird, the actual timeout here is from map_task_to_instance(task) which is a single indexed database lookup. This is normally a fast lookup. It is nested, so this isn't the fastest if you have a thousand+ tasks to look up, but it still shouldn't take over the worker timeout to execute.

Try resetting your tasks to start with:

https://github.com/meeb/tubesync/blob/main/docs/reset-tasks.md

gardiol commented 7 hours ago

Resetting the tasks indeed helped a lot, now tasks have somehow restarted (at least indexing is running)... Will check in a bit if it keeps doing the same...

gardiol commented 7 hours ago

Can say that while immediately the tasks page loaded fine, after a couple of minuties i get the 502 random errors again.

meeb commented 7 hours ago

Providing your number of tasks is going down at some point it'll start working. The /tasks page just lists tasks really it doesn't do a lot. Just curious, but what platform are you running this on? And what database are you using?

gardiol commented 7 hours ago

I am on Gentoo Linux (i7 9th gen, 48gb RAM) CLI only system shared with other services indeed, but as i said, very low load.

I am only running the docker compose. This is the setup i am using

meeb commented 7 hours ago

Looks fine, is your /config volume on a reasonably fast disk?

gardiol commented 7 hours ago

It's on a Linux software RAID1, but it's on an external USB JBOD, so not the fastest atually... Might try to move it to an internal SSD if that would help significantly?

meeb commented 7 hours ago

Yeah, querying an SQLite database running on a USB mounted hard drive is going to be slow.

gardiol commented 7 hours ago

Ok, moved, will let you know.