Memory leak when using pluggable loggers

[chekunkov]

Hi, I think I've discovered a memory leak that happens when logger = file:<filepath> or req-logger = file:<filepath> appears in uwsgi config.

On the following image you'll see memory usage for 2 different versions of uwsgi + flask service.

As you can see (1) consumes ±the same amount of memory while memory usage for (2) growth constantly. Growth stops when (2) stops receiving requests.

(1) has config:

[uwsgi]
http = 0.0.0.0:5002
http-timeout = 300
uid = daemon
chdir = /app
module = myapp.uwsgi
callable = app
processes = 3
threads = 10
buffer-size = 65535
stats = 0.0.0.0:9191
# logger = file:/some/filepath
log-format = %(addr) - %(username) [%(ltime)] "%(method) %(uri) %(proto)" %(status) %(rsize) "%(referer)" "%(uagent)" %(msecs)
honour-stdin =

(2) has logger uncommented:

[uwsgi]
http = 0.0.0.0:5002
http-timeout = 300
uid = daemon
chdir = /app
module = myapp.uwsgi
callable = app
processes = 3
threads = 10
buffer-size = 65535
stats = 0.0.0.0:9191
logger = file:/some/filepath
log-format = %(addr) - %(username) [%(ltime)] "%(method) %(uri) %(proto)" %(status) %(rsize) "%(referer)" "%(uagent)" %(msecs)
honour-stdin =

Both versions run in the same docker image scrapinghub/python:3 https://hub.docker.com/r/scrapinghub/python/tags/

I tried uwsgi 2.0.10 and 2.0.13.1 - same results. Same happens if I replace logger with req-logger.

Is there any other info I can provide to help to debug this issue?

[chekunkov]

Quick update: if I'm not missing something logger and req-logger imply log-master = true, so I tested with it and without logger or req-logger (3) - memory usage doesn't change.

[uwsgi]
http = 0.0.0.0:5002
http-timeout = 300
uid = daemon
chdir = /app
module = myapp.uwsgi
callable = app
processes = 3
threads = 10
buffer-size = 65535
stats = 0.0.0.0:9191
log-master = true
# logger = file:/some/filepath
# req-logger = file:/some/filepath
log-format = %(addr) - %(username) [%(ltime)] "%(method) %(uri) %(proto)" %(status) %(rsize) "%(referer)" "%(uagent)" %(msecs)
honour-stdin =

[xrmx]

If you can run the thing under valgrind that would be much helpful to sort out if there's something wrong.

[chekunkov]

@xrmx should I follow the instructions from https://github.com/unbit/uwsgi/blob/master/valgrind/README and replace [ARGS] with a command I'm using to run uwsgi+flask?

[xrmx]

@chekunkov that should work

[max8899]

@chekunkov some new update? same problem here in my production env

[unbit]

@max8899 can you report your full config ?

[max8899]

@unbit below is my config

[uwsgi]

chdir           =  /home
env = DJANGO_SETTINGS_MODULE=app.settings
module = django.core.wsgi:get_wsgi_application()
master          = true
processes       = 5
socket          = app.sock
chmod-socket    = 666
vacuum          = true

max-worker-lifetime = 1800
max-requests = 50000

// with this config will cause memory issue
req-logger      = file:/var/log/uwsgi/furion-req.log
logger          = file:/var/log/uwsgi/worker.log