Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Possible memory leak. #103

Closed
Mr-Cake opened this issue Mar 23, 2021 · 37 comments
Closed

Possible memory leak. #103

Mr-Cake opened this issue Mar 23, 2021 · 37 comments
Labels
bug Something isn't working
Projects
Milestone

Comments

@Mr-Cake
Copy link

Mr-Cake commented Mar 23, 2021

v0.9.1 docker

Container stats off at 230mb.
After running for a couple of days memory usage of docker container has grown to 1.4gb.
/usr/bin/python3 /app/manage.py process_tasks is the process using all the ram.

@meeb
Copy link
Owner

meeb commented Mar 24, 2021

Hi, thanks for the report. It's possible you have indeed found a memory leak. I'll spin up a long running test task for a few days to see if I can replicate it.

@meeb meeb added the bug Something isn't working label Mar 24, 2021
@meeb meeb added this to Triage in Development via automation Mar 24, 2021
@meeb meeb added this to the v1.1 milestone Mar 24, 2021
@meeb meeb moved this from Triage to Bugs in Development Mar 24, 2021
@Mr-Cake
Copy link
Author

Mr-Cake commented Mar 24, 2021

I don't know how to dive in anymore than htop sorry, if it helps i have 6 sources. I also made it refresh tasks after restarting and it jumped to 900mb straight away.

@meeb
Copy link
Owner

meeb commented Mar 24, 2021

When you index a channel or playlist with youtube-dl it crawls away and then returns a massive object of all the videos and a bit of metadata. For large channels this can be a pretty big object and use up quite a lot of RAM.

There's not much that can be done to avoid this, potentially with hooking deep into youtube-dl internals which I would probably be against from a stability and ongoing maintenance perspective.

Given the way the indexer works it will spike in RAM usage when indexing, probably to several hundred mb or more when indexing a large channel. However, this should eventually be freed by the GC once the indexing is complete. It would be a bug if the worker continually increased in RAM usage, but probably not a bug if it was stable at a moderately high usage. Can you paste links to your 6 channels if you don't mind them being public, I'll set up an instance the directly replicates your setup and check it.

@Mr-Cake
Copy link
Author

Mr-Cake commented Mar 24, 2021

Sure,

https://www.youtube.com/channel/UCp-mnssZd4X2bgIcekaNfgA
https://www.youtube.com/channel/UCUujfNBK9uv3cIW-P5PX7vA
https://www.youtube.com/channel/UCFUBt5_cGJpt58XBIh4RtNA
https://www.youtube.com/channel/UC_JILA9Hg517dKdMb3n2OrQ
https://www.youtube.com/channel/UCyGT_yinKL7uRiZmTjC17RQ
https://www.youtube.com/user/eaterbc

My setting are 3hour check, Download Cap @ 7 days, Delete after 10days, 4k if available.
It's increased a little since starting, up to 1.2gb now.

Yours is the first docker youtubedl implementation that doesn't fall over straight away so great job!!

@meeb
Copy link
Owner

meeb commented Mar 24, 2021

Thanks for the channels, I'll have a go at replicating your situation. If the worker is stable at 1.2gb that's probably "normal" unfortunately, but it may be possible to get it a bit lower and have the GC kick in a bit faster.

@Mr-Cake
Copy link
Author

Mr-Cake commented Mar 28, 2021

An update, on my system (Unraid docker 16gb ram) each task uses around 250mb of ram and never gets freed.

@meeb
Copy link
Owner

meeb commented Mar 30, 2021

Just to clarify, by task do you mean channel to index? There should be only one "task" running at once ever in terms of work tasks.

@Mr-Cake
Copy link
Author

Mr-Cake commented Mar 30, 2021

Yea, after each scheduled task runs the memory is never freed. This is after 40hrs of uptime.
image

@meeb
Copy link
Owner

meeb commented Mar 30, 2021

OK, thanks. Does it stay stable at that amount of RAM usage? 40+ hours should be enough to have the tasks run a couple of times each. While high, if it's not increasing that's less of a concern initially.

@Mr-Cake
Copy link
Author

Mr-Cake commented Mar 30, 2021

Yea, after watching it for a while each time a task ran it jumped around 250mb, doesn't increase past that just never releases it i guess. Topped out at 1.8gb with 7 sources.

I'm guessing they run fine on your system, after a task runs the ram usage goes back to just nginx + other stuff?

@Mr-Cake
Copy link
Author

Mr-Cake commented Mar 30, 2021

Might be something, i was looking to see whats downloaded an noticed it hasn't been deleting files. Maybe its getting hung up there?

@meeb
Copy link
Owner

meeb commented Mar 31, 2021

The not-deleting-files thing is probably #67 - it shouldn't use any more RAM, it just does a "if this filename exists delete it" check so it won't block anything. As for the tasks I can see they use a set amount of RAM then flatline at that usage even after re-running the indexing tasks again later via the scheduler. This would imply the data structures get re-used or deleted and re-allocated, but persist once the task is complete. There's no clear obvious point this occurs as there's no massive objects passed back from the tasks once they complete or anything, but I'll try stuffing in a bunch of del varname and gc.collect() calls at the end of the indexing tasks to see if this kicks in the GC to clean up and free the RAM usage. If that doesn't do it I'll attach a profiler and attempt to see where it's being stored. In the short term I'm relatively happy the RAM usage is stable, if high, so while not ideal and annoying it shouldn't be a stability problem if you have the RAM available.

@Mr-Cake
Copy link
Author

Mr-Cake commented Mar 31, 2021

Ah right just a coincidence then. After watching it for longer i agree it's not a leak. Memory in use just not freed when it could be. Like you say just not ideal.

@ExodusC ExodusC mentioned this issue Aug 8, 2021
@csjoh
Copy link

csjoh commented Dec 22, 2021

I've seen a huge uptake on memory use for my container on unRAID.

I've got 4 channels with currently a total of 811 media items, and TubeSync is using 24.6GB memory. I'm using an external mariaDB database as the sqlite3 database didn't work for me.

The memory usage ballooning happened a few TubeSync updates ago; it went from about 300MB to the currently absurd 24.6GB. It is stable at this point, but with the low number of channels and media items, I'm wondering what the cause of this could be.

I'm happy to provide logs if required.

@meeb
Copy link
Owner

meeb commented Dec 22, 2021

Wow that does indeed sound like a pretty severe leak. Are the 4 channels very large? And does the memory usage return to normal when you restart the container?

@csjoh
Copy link

csjoh commented Dec 26, 2021

Wow that does indeed sound like a pretty severe leak. Are the 4 channels very large? And does the memory usage return to normal when you restart the container?

I'm not sure what constitutes a very large channel, one has about 450 videos, another has around 700, one with 16 and one with 27. Nothing extravagant, I feel.

Over the Christmas weekend, memory usage has doubled to 49GB.

On restart (or complete stop, then start), memory usage gets to about 241-243MB and stays there for a little while, then starts to slowly rise.

@csjoh
Copy link

csjoh commented Dec 26, 2021

Here's a log snippet from the latest startup just now:

[s6-init] making user provided files available at /var/run/s6/etc...exited 0.
[s6-init] ensuring user provided files have correct perms...exited 0.
[fix-attrs.d] applying ownership & permissions fixes...
[fix-attrs.d] done.
[cont-init.d] executing container initialization scripts...
[cont-init.d] 10-tubesync: executing...
usermod: no changes
2021-12-26 15:33:13,677 [tubesync/INFO] Using database connection: django.db.backends.mysql://tubesync:[hidden]@192.168.2.8:3306/tubesync
Operations to perform:
Apply all migrations: admin, auth, background_task, contenttypes, sessions, sync
Running migrations:
No migrations to apply.
Your models in app(s): 'sync' have changes that are not yet reflected in a migration, and so won't be applied.
Run 'manage.py makemigrations' to make new migrations, and then re-run 'manage.py migrate' to apply them.
[cont-init.d] 10-tubesync: exited 0.
[cont-init.d] done.
[services.d] starting services
[services.d] done.
458:C 26 Dec 2021 15:33:14.383 # oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
458:C 26 Dec 2021 15:33:14.383 # Redis version=6.0.16, bits=64, commit=00000000, modified=0, pid=458, just started
458:C 26 Dec 2021 15:33:14.383 # Configuration loaded
458:M 26 Dec 2021 15:33:14.385 * Running mode=standalone, port=6379.
458:M 26 Dec 2021 15:33:14.386 # Server initialized
458:M 26 Dec 2021 15:33:14.386 # WARNING overcommit_memory is set to 0! Background save may fail under low memory condition. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
458:M 26 Dec 2021 15:33:14.386 # WARNING you have Transparent Huge Pages (THP) support enabled in your kernel. This will create latency and memory usage issues with Redis. To fix this issue run the command 'echo madvise > /sys/kernel/mm/transparent_hugepage/enabled' as root, and add it to your /etc/rc.local in order to retain the setting after a reboot. Redis must be restarted after THP is disabled (set to 'madvise' or 'never').
458:M 26 Dec 2021 15:33:14.387 * Ready to accept connections
[2021-12-26 15:33:14 +0100] [460] [INFO] Starting gunicorn 20.1.0
[2021-12-26 15:33:14 +0100] [460] [INFO] Listening at: http://127.0.0.1:8080 (460)
[2021-12-26 15:33:14 +0100] [460] [INFO] Using worker: sync
[2021-12-26 15:33:14 +0100] [517] [INFO] Booting worker with pid: 517
2021-12-26 15:33:14,631 [tubesync/INFO] Using database connection: django.db.backends.mysql://tubesync:[hidden]@192.168.2.8:3306/tubesync
[2021-12-26 15:33:14 +0100] [518] [INFO] Booting worker with pid: 518
[2021-12-26 15:33:14 +0100] [519] [INFO] Booting worker with pid: 519
2021-12-26 15:33:14,839 [tubesync/INFO] Using database connection: django.db.backends.mysql://tubesync:[hidden]@192.168.2.8:3306/tubesync
2021-12-26 15:33:14,937 [tubesync/INFO] Using database connection: django.db.backends.mysql://tubesync:[hidden]@192.168.2.8:3306/tubesync
2021-12-26 15:33:14,993 [tubesync/INFO] Using database connection: django.db.backends.mysql://tubesync:[hidden]@192.168.2.8:3306/tubesync

@csjoh
Copy link

csjoh commented Dec 26, 2021

Interaction with the WebUI sees memory usage shoot from 241MB to 3.5GB pretty much instantly, and it remains there.

I went from the source list to the dashboard to the media list and back to the dashboard.

Editing a source rises the memory usage further to 8.7GB. As a side note; editing sources pretty consistently crashes the nginx server resulting in a 502 Bad Gateway error message.

Log snippet from the crash:

[2021-12-26 15:48:50 +0100] [460] [CRITICAL] WORKER TIMEOUT (pid:519)
2021/12/26 15:48:50 [error] 481#481: *405 upstream prematurely closed connection while
reading response header from upstream, client: 192.168.2.2, server: _, request:
"POST /source-update/ac99d3d8-8d27-4576-a08d-1afa467e5e95 HTTP/1.1", upstream:
"http://127.0.0.1:8080/source-update/ac99d3d8-8d27-4576-a08d-1afa467e5e95", host:
"192.168.2.8:4848", referrer: "http://192.168.2.8:4848/source-update/ac99d3d8-8d27-4576-a08d-1afa467e5e95"

I'm not at all sure what happened there, but I saw the same behaviour when using the sqlite3 backend, only a lot more frequently and not just when editing sources.

@meeb
Copy link
Owner

meeb commented Dec 28, 2021

Editing (saving) a source is currently extremely intensive, it checks every media item linked to the source to see if any state has changed (such as, you changed the date range you want to keep media for and it may need to trigger more downloads for older media). This is being replaced with a watchdog sort of process shortly. Other interactions with the dashboard outside of saving a source shouldn't incur extreme use of memory though as they're just straight Django views with read-only content.

@csjoh
Copy link

csjoh commented Jan 2, 2022

Editing (saving) a source is currently extremely intensive, it checks every media item linked to the source to see if any state has changed (such as, you changed the date range you want to keep media for and it may need to trigger more downloads for older media). This is being replaced with a watchdog sort of process shortly. Other interactions with the dashboard outside of saving a source shouldn't incur extreme use of memory though as they're just straight Django views with read-only content.

Yeah, I can understand that, but surely nearly 50GB memory usage seems a bit excessive? I've got 144GB in my server, but still, it'd be nice to have some for other processes too...

@meeb
Copy link
Owner

meeb commented Jan 2, 2022

Oh absolutely, 50GB is totally insane and something is very wrong there. I was explaining the memory usage spike for saving a source in the UI. How are you measuring the memory usage?

@csjoh
Copy link

csjoh commented Jan 2, 2022

Oh absolutely, 50GB is totally insane and something is very wrong there. I was explaining the memory usage spike for saving a source in the UI. How are you measuring the memory usage?

I'm just using unRAID's WebUI to look at memory usage:

image

The container was started about an hour ago and I haven't really done anything with it, it's just sitting there doing its thing. I guess it has run some background synchronizing tasks to keep the channels up to date, but I haven't interacted with it.

@meeb
Copy link
Owner

meeb commented Jan 3, 2022

Hm, it would be interesting to see what's actually running in the container. I'd be amazed if the worker was actually allocating anything close to that. Can you drop into a shell in the tubesync container? If so, something like this (typed in the container shell) would be helpful:

$ apt update
$ apt install procps
$ ps auxwww

Just a process list with VSZ / RSS usage of each process in the container.

@csjoh
Copy link

csjoh commented Jan 3, 2022

Here's the ps output:

# ps auxwww
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         1  0.0  0.0    204     4 ?        Ss   03:31   0:00 s6-svscan -t0 /var/run/s6/services
root        38  0.0  0.0    204     4 ?        S    03:31   0:00 s6-supervise s6-fdholderd
root       452  0.0  0.0    204     4 ?        S    03:31   0:00 s6-supervise gunicorn
root       453  0.0  0.0    204     4 ?        S    03:31   0:00 s6-supervise nginx
root       454  0.0  0.0    204     4 ?        S    03:31   0:00 s6-supervise redis
root       456  0.0  0.0    204     4 ?        S    03:31   0:00 s6-supervise tubesync-worker
root       458  0.0  0.0   6836  3204 ?        Ss   03:31   0:00 bash ./run
app        459  0.0  0.0  30084 22872 ?        Ss   03:31   0:03 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
redis      460  0.1  0.0  52816 19816 ?        Ssl  03:31   0:27 /usr/bin/redis-server 127.0.0.1:6379
app        461  0.4  0.6 1687260 980588 ?      Ssl  03:31   1:38 /usr/bin/python3 /app/manage.py process_tasks
root       471  0.0  0.0   8472  5964 ?        S    03:31   0:00 nginx: master process /usr/sbin/nginx
app        480  0.0  0.0   9004  3320 ?        S    03:31   0:00 nginx: worker process
app        481  0.0  0.0   8992  3308 ?        S    03:31   0:00 nginx: worker process
app        482  0.0  0.0   8928  3016 ?        S    03:31   0:00 nginx: worker process
app        483  0.0  0.0   8928  2560 ?        S    03:31   0:00 nginx: worker process
app        484  0.0  0.0   8928  3016 ?        S    03:31   0:00 nginx: worker process
app        485  0.0  0.0   8928  3016 ?        S    03:31   0:00 nginx: worker process
app        486  0.0  0.0   8928  3016 ?        S    03:31   0:00 nginx: worker process
app        487  0.0  0.0   8928  2560 ?        S    03:31   0:00 nginx: worker process
app        488  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        489  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        490  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        491  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        492  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        493  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        494  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        495  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        496  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        497  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        498  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        499  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        500  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        501  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        502  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        503  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        504  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        505  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        506  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        507  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        508  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        509  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        510  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        511  0.0  0.0   8928  2564 ?        S    03:31   0:00 nginx: worker process
app        517  0.0  0.0 120932 67840 ?        S    03:31   0:01 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
app        518  0.0  0.1 251564 198732 ?       S    03:31   0:03 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
app        519  0.0  0.0 123372 70448 ?        S    03:31   0:01 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
root      3167  0.0  0.0   2420   520 pts/0    Ss   09:46   0:00 sh
root      3558  0.0  0.0   9700  3260 pts/0    R+   09:49   0:00 ps auxwww

It bears to mention that there was an update available last night, which I installed. That update seems to have stabilized the memory usage at reasonable levels again, it now idles at around 450MB memory and shot up to 1.345GB when I added a new channel with 890 videos. It's currently synchronizing the channel and downloading happily and everything looks good so far.

I'll keep an eye on it and report back later.

@meeb
Copy link
Owner

meeb commented Jan 3, 2022

Thanks for the details. There's nothing too out of the ordinary in that process list, the most intensive task is the worker as expected but that's sitting around 0.93gb of RSS so I assume it's indexing a large channel when you ran ps. There's nothing that should have changed particularly in recent releases that appears to fix a memory leak, though.

If it goes insane again (multiple tens of gigabytes of reported usage) paste the process list in this issue. If there's a mismatch between what the processes are actually using and what Unraid is reporting as being used it may just be the container being allocated RAM as it was being quite active and not released again because you have so much RAM in your server and there's no requirement to free it. I don't use Unraid myself, but general Linux systems allocate most or all of the RAM over time for various caches depending on which statistic is being tracked for the Unraid RAM usage graph (the typical free shows all RAM used, but ps does not situation).

@csjoh
Copy link

csjoh commented Jan 3, 2022

I've been stress testing the container today by adding and removing channels, syncing and resyncing, and it never went over 1.8GB memory usage. That kind of amount is completely acceptable. :)

With regards to Unraid's memory allocation/deallocation routines, I can't really say. It's based on Slackware (sort of -current, but kind of a snapshot at the same time) with a proprietary web ui on top, so I would think they leverage stock Linux/Docker functions for the actual docker administration.

Anyway, I'll keep an eye on the resource use and report back if it starts getting out of control again.

@meeb
Copy link
Owner

meeb commented Jan 3, 2022

Good news! Thanks for the feedback. I'll close this issue for now, but if you have any future problems relating to memory usage comment again here and I'll open it back up again.

@meeb meeb closed this as completed Jan 3, 2022
@csjoh
Copy link

csjoh commented Jan 3, 2022

Aaand it's back to 26GB memory usage.

I also spun up a second instance for audio-only downloads, and that sits around 13GB with two sources and about 1900 items total.

ps output for each of the containers:

Video-only:

# ps auxwww
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         1  0.0  0.0    204     4 ?        Ss   16:06   0:00 s6-svscan -t0 /var/run/s6/services
root        38  0.0  0.0    204     4 ?        S    16:06   0:00 s6-supervise s6-fdholderd
root       452  0.0  0.0    204     4 ?        S    16:07   0:00 s6-supervise gunicorn
root       453  0.0  0.0    204     4 ?        S    16:07   0:00 s6-supervise nginx
root       454  0.0  0.0    204     4 ?        S    16:07   0:00 s6-supervise redis
root       456  0.0  0.0    204     4 ?        S    16:07   0:00 s6-supervise tubesync-worker
app        458  0.0  0.0  30084 22360 ?        Ss   16:07   0:03 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
root       459  0.0  0.0   6836  2532 ?        Ss   16:07   0:00 bash ./run
redis      460  0.1  0.0  52816 20980 ?        Ssl  16:07   0:32 /usr/bin/redis-server 127.0.0.1:6379
app        461  1.1 17.0 27068488 25280624 ?   Ssl  16:07   5:05 /usr/bin/python3 /app/manage.py process_tasks
root       472  0.0  0.0   8472  5820 ?        S    16:07   0:00 nginx: master process /usr/sbin/nginx
app        480  0.0  0.0   9316  3676 ?        S    16:07   0:00 nginx: worker process
app        481  0.0  0.0   8960  3128 ?        S    16:07   0:00 nginx: worker process
app        482  0.0  0.0   8928  2988 ?        S    16:07   0:00 nginx: worker process
app        483  0.0  0.0   8928  3096 ?        S    16:07   0:00 nginx: worker process
app        484  0.0  0.0   8928  2864 ?        S    16:07   0:00 nginx: worker process
app        485  0.0  0.0   8928  2984 ?        S    16:07   0:00 nginx: worker process
app        486  0.0  0.0   8928  2400 ?        S    16:07   0:00 nginx: worker process
app        487  0.0  0.0   8928  2400 ?        S    16:07   0:00 nginx: worker process
app        488  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        489  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        490  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        491  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        492  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        493  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        494  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        495  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        496  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        497  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        498  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        499  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        500  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        501  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        502  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        503  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        504  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        505  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        506  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        507  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        508  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        509  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        510  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        511  0.0  0.0   8928  2404 ?        S    16:07   0:00 nginx: worker process
app        517  0.0  0.0 115684 62708 ?        S    16:07   0:01 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
app        518  0.0  0.4 703988 651252 ?       S    16:07   0:12 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
app        519  0.0  1.3 2032556 1979624 ?     S    16:07   0:05 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
root      3683  0.6  0.0   2420   592 pts/0    Ss   23:15   0:00 sh
root      3689  0.0  0.0   9700  3192 pts/0    R+   23:15   0:00 ps auxwww

Audio-only:

# ps auxwww
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         1  0.0  0.0    204     4 ?        Ss   22:32   0:00 s6-svscan -t0 /var/run/s6/services
root        38  0.0  0.0    204     4 ?        S    22:32   0:00 s6-supervise s6-fdholderd
root       452  0.0  0.0    204     4 ?        S    22:32   0:00 s6-supervise gunicorn
root       453  0.0  0.0    204     4 ?        S    22:32   0:00 s6-supervise nginx
root       455  0.0  0.0    204     4 ?        S    22:32   0:00 s6-supervise redis
root       456  0.0  0.0    204     4 ?        S    22:32   0:00 s6-supervise tubesync-worker
root       458  0.0  0.0   6836  3368 ?        Ss   22:32   0:00 bash ./run
app        459  0.0  0.0  30084 22956 ?        Ss   22:32   0:00 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
redis      460  0.1  0.0  52816 21564 ?        Ssl  22:32   0:04 /usr/bin/redis-server 127.0.0.1:6379
app        461 29.3  5.2 8699556 7713924 ?     Ssl  22:32  13:03 /usr/bin/python3 /app/manage.py process_tasks
root       472  0.0  0.0   8472  6116 ?        S    22:32   0:00 nginx: master process /usr/sbin/nginx
app        480  0.0  0.0   9240  4052 ?        S    22:32   0:00 nginx: worker process
app        481  0.0  0.0   9064  3800 ?        S    22:32   0:00 nginx: worker process
app        482  0.0  0.0   8928  2608 ?        S    22:32   0:00 nginx: worker process
app        483  0.0  0.0   8928  2608 ?        S    22:32   0:00 nginx: worker process
app        484  0.0  0.0   8928  2608 ?        S    22:32   0:00 nginx: worker process
app        485  0.0  0.0   8928  2608 ?        S    22:32   0:00 nginx: worker process
app        486  0.0  0.0   8928  2608 ?        S    22:32   0:00 nginx: worker process
app        487  0.0  0.0   8928  2608 ?        S    22:32   0:00 nginx: worker process
app        488  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        489  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        490  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        491  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        492  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        493  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        494  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        495  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        496  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        497  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        498  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        499  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        500  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        501  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        502  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        503  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        504  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        505  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        506  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        507  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        508  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        509  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        510  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        513  0.0  0.0   8928  2612 ?        S    22:32   0:00 nginx: worker process
app        532  0.1  1.1 1756528 1703692 ?     S    22:34   0:03 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
app        605  0.2  2.2 3391032 3338604 ?     S    22:42   0:05 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
app        614  0.0  0.0 115460 62516 ?        S    22:43   0:00 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
root      3252  0.0  0.0   2420   528 pts/0    Ss   23:16   0:00 sh
root      3625  0.0  0.0   9700  3312 pts/0    R+   23:17   0:00 ps auxwww

@meeb
Copy link
Owner

meeb commented Jan 4, 2022

OK, thanks that's helpful. That does seem a lot. Even the gunicorn workers are allocating gigabytes and they're straight normal Django with nothing fancy. Can you try editing the container config in Unraid and limiting its ability to allocate memory and see what happens? I believe you can just edit in additional custom flags and add in --memory=4G or something as a test.

@meeb meeb reopened this Jan 4, 2022
Development automation moved this from Bugs to Triage Jan 4, 2022
@csjoh
Copy link

csjoh commented Jan 4, 2022

Done.

The change shows up in the unRAID webui:

image

The screenshot was taken less than a minute after restarting the containers, hence the low memory usage.

I'll stress test (i.e. use) them for a bit and see what happens, but yesterday it seemed like they behaved normally while being used, but when I left them alone after a bit of use (navigation, enabling disabled items, etc), the memory use rose dramatically. I'll do the same today and then leave them alone for a few hours and see if I can replicate the problem.

@meeb
Copy link
Owner

meeb commented Jan 4, 2022

Thanks for testing. Hopefully it'll behave itself when given a (still very generous) sensible limit.

@csjoh
Copy link

csjoh commented Jan 5, 2022

Quick update:

My TubeSync video-only container sits around 480MB memory usage and seems happy, despite being limited to 4GB total.

My TubeSync audio-only container, however, hovers around 3.8GB ram while it's apparently doing nothing. This container is also limited to 4GB total RAM, so in any case it can't spin out of control.

PS outputs:

Video container:

# ps auxwww
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         1  0.0  0.0    204     4 ?        Ss   Jan04   0:00 s6-svscan -t0 /var/run/s6/services
root        35  0.0  0.0    204     4 ?        S    Jan04   0:00 s6-supervise s6-fdholderd
root       453  0.0  0.0    204     4 ?        S    Jan04   0:00 s6-supervise gunicorn
root       454  0.0  0.0    204     4 ?        S    Jan04   0:00 s6-supervise nginx
root       456  0.0  0.0    204    24 ?        S    Jan04   0:00 s6-supervise tubesync-worker
root       457  0.0  0.0    204     4 ?        S    Jan04   0:00 s6-supervise redis
root       459  0.0  0.0   6836   232 ?        Ss   Jan04   0:00 bash ./run
app        460  2.2  0.0  30084 14296 ?        Ss   Jan04  48:18 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
redis      463  2.0  0.0  52816 13288 ?        Ssl  Jan04  45:49 /usr/bin/redis-server 127.0.0.1:6379
root       474  0.0  0.0   8472   840 ?        S    Jan04   0:00 nginx: master process /usr/sbin/nginx
app        481  0.0  0.0   9456  1564 ?        S    Jan04   0:00 nginx: worker process
app        482  0.0  0.0   9068  1528 ?        S    Jan04   0:00 nginx: worker process
app        483  0.0  0.0   9008  1396 ?        S    Jan04   0:00 nginx: worker process
app        484  0.0  0.0   8928  1280 ?        S    Jan04   0:00 nginx: worker process
app        485  0.0  0.0   9008  1392 ?        S    Jan04   0:00 nginx: worker process
app        486  0.0  0.0   8928  1260 ?        S    Jan04   0:00 nginx: worker process
app        487  0.0  0.0   8928  1260 ?        S    Jan04   0:00 nginx: worker process
app        488  0.0  0.0   8928  1260 ?        S    Jan04   0:00 nginx: worker process
app        489  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        490  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        491  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        492  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        493  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        494  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        495  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        496  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        497  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        498  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        499  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        500  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        501  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        502  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        503  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        504  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        505  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        506  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        507  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        508  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        509  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        510  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        511  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        512  0.0  0.0   8928  1120 ?        S    Jan04   0:00 nginx: worker process
app        518  1.3  0.1 354476 292816 ?       S    Jan04  29:59 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
app      13433  2.0  0.0 142864 80168 ?        S    05:40  19:15 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
app      18160  2.3  0.0 115512 50716 ?        S    12:38  12:15 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
app      23993  2.1  0.2 1119912 356512 ?      Ssl  21:16   0:04 /usr/bin/python3 /app/manage.py process_tasks
root     24017  0.1  0.0   2420   592 pts/0    Ss   21:19   0:00 sh
root     24359  0.0  0.0   9700  3432 pts/0    R+   21:19   0:00 ps auxwww

Audio container:

# ps auxwww
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
root         1  0.0  0.0    204     4 ?        Ss   Jan04   0:00 s6-svscan -t0 /var/run/s6/services
root        35  0.0  0.0    204     4 ?        S    Jan04   0:00 s6-supervise s6-fdholderd
root       453  0.0  0.0    204     4 ?        S    Jan04   0:00 s6-supervise nginx
root       454  0.0  0.0    204     4 ?        S    Jan04   0:00 s6-supervise gunicorn
root       456  0.0  0.0    204     4 ?        S    Jan04   0:00 s6-supervise tubesync-worker
root       457  0.0  0.0    204     4 ?        S    Jan04   0:00 s6-supervise redis
app        459  0.0  0.0  30084 22760 ?        Ss   Jan04   0:17 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
root       460  0.0  0.0   6836  3300 ?        Ss   Jan04   0:00 bash ./run
redis      462  0.1  0.0  52816 21508 ?        Ssl  Jan04   2:59 /usr/bin/redis-server 127.0.0.1:6379
app        463  0.3  2.3 4077844 3444252 ?     Ssl  Jan04   8:25 /usr/bin/python3 /app/manage.py process_tasks
root       474  0.0  0.0   8472  6084 ?        S    Jan04   0:00 nginx: master process /usr/sbin/nginx
app        481  0.0  0.0   9288  4088 ?        S    Jan04   0:05 nginx: worker process
app        482  0.0  0.0   8928  3204 ?        S    Jan04   0:00 nginx: worker process
app        483  0.0  0.0   8928  3212 ?        S    Jan04   0:00 nginx: worker process
app        484  0.0  0.0   8928  3204 ?        S    Jan04   0:00 nginx: worker process
app        485  0.0  0.0   8928  2572 ?        S    Jan04   0:00 nginx: worker process
app        486  0.0  0.0   8928  2572 ?        S    Jan04   0:00 nginx: worker process
app        487  0.0  0.0   8928  2572 ?        S    Jan04   0:00 nginx: worker process
app        488  0.0  0.0   8928  2572 ?        S    Jan04   0:00 nginx: worker process
app        489  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        490  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        491  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        492  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        493  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        494  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        495  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        496  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        497  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        498  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        499  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        500  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        501  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        502  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        503  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        504  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        505  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        506  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        507  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        508  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        509  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        510  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        511  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        512  0.0  0.0   8928  2576 ?        S    Jan04   0:00 nginx: worker process
app        518  0.0  0.1 291416 239908 ?       S    Jan04   0:15 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
app        519  0.0  0.0 177136 124448 ?       S    Jan04   0:20 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
app       4280  0.0  0.0 123280 70616 ?        S    Jan04   0:04 /usr/bin/python3 /usr/local/bin/gunicorn -c /app/tubesync/gunicorn.py --capture-output tubesync.wsgi:application
root     17032  0.0  0.0   2420   528 pts/0    Ss   21:20   0:00 sh
root     17355  0.0  0.0   9700  3296 pts/0    R+   21:21   0:00 ps auxwww

@meeb
Copy link
Owner

meeb commented Jan 6, 2022

Interesting that the audio-only instance worker seems to be the one causing the issues. That might imply an upstream issue, but I'll look into hacking in some force-object-deletion code in to see if I can encourage the GC to clear it up.

Is your media downloading and does everything appear to generally be working with the 4G limits in place?

@csjoh
Copy link

csjoh commented Jan 6, 2022

They seem to be taking turns on chewing on the memory banks :) Previously it was the video container that was hogging the RAM, now it's the audio one.

But yeah, they both seem to be working properly. They both download what they're supposed to and they are responsive when navigating.

However, the video container consistently times out with a 502 Bad Gateway message when editing (actually saving) a specific source, resetting tasks or trying to delete said source.

The audio container did this too when setting it up, as I duplicated the database from the video container and renamed it, and trying to clean that up for audio downloads only was a bit of a pain (ref #196) as everything I tried just timed out. Now that I'm aware of the command line black magic it's no longer a problem as such, and I also want to keep the source as it is. I'm curious to find the reason why it messes up TubeSync so badly, though, but I'm not sure how to approach the problem.

@meeb
Copy link
Owner

meeb commented Jan 7, 2022

The 502 nonsense will be fixed when I finally get time to replace the current worker / queue system and offload the work done in background signals to background tasks. There's not a great deal that can be done in the short term to fix it.

@csjoh
Copy link

csjoh commented Jan 11, 2022

It's been a few days, the containers have been doing their thing over the weekend and got a restart early Sunday morning when unRAID does its appdata (docker container) backup routine. Since then, they seem to have settled around 250MB at idle and use up to 3.6-3.8GB when doing resyncs of the sources, but they also seem to better release memory back to the docker daemon/unRAID to use for other processes.

I think it's under control at the moment and as such this issue can be closed again. If new and weird things start happening I'll reopen the issue or create a new one.

@meeb
Copy link
Owner

meeb commented Jan 11, 2022

Cheers, thanks for the feedback. Given you've not experienced the containers allocating more RAM than their limits or being otherwise terminated for running out of RAM it's probably safe to assume it's just buffers using up your available RAM because you have loads of it. I'll close the issue again, but comment back if anything weird happens.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
Development

No branches or pull requests

3 participants