unbit / uwsgi

uWSGI application server container
http://projects.unbit.it/uwsgi
Other
3.46k stars 691 forks source link

uwsgi creates spooler dirs and leaves them writable by root only #1858

Open jpic opened 6 years ago

jpic commented 6 years ago

I noticed my deployment broke when i added multiple spoolers, ie. with --spooler=/spooler/mail --spooler=/spooler/stat: it would create the mail and stat directories inside /spooler and leave them writable by root only.

Then, it seems uwsgi's spooler is stuck in an endless loop trying to write inside this directory after changing uid from root.

spawned the uWSGI spooler on dir /spooler/mail with pid 15317                          OOOPS the spooler is no more...trying respawn...                                       spawned the uWSGI spooler on dir /spooler/stat with pid 15318                          
chdir(): Permission denied [core/spooler.c line 437]                                   chdir(): Permission denied [core/spooler.c line 437]                                   OOOPS the spooler is no more...trying respawn...                                       spawned the uWSGI spooler on dir /spooler/mail with pid 15319                          
OOOPS the spooler is no more...trying respawn...                                       chdir(): Permission denied [core/spooler.c line 437]                                   spawned the uWSGI spooler on dir /spooler/stat with pid 15320                          
chdir(): Permission denied [core/spooler.c line 437]                                   OOOPS the spooler is no more...trying respawn...                                       spawned the uWSGI spooler on dir /spooler/mail with pid 15321                          
OOOPS the spooler is no more...trying respawn...                                       chdir(): Permission denied [core/spooler.c line 437]                                   spawned the uWSGI spooler on dir /spooler/stat with pid 15322                          
chdir(): Permission denied [core/spooler.c line 437]                                   OOOPS the spooler is no more...trying respawn...                                       spawned the uWSGI spooler on dir /spooler/mail with pid 15323                          
OOOPS the spooler is no more...trying respawn...                                       chdir(): Permission denied [core/spooler.c line 437]                                   spawned the uWSGI spooler on dir /spooler/stat with pid 15324                          chdir(): Permission denied [core/spooler.c line 437]                                   
OOOPS the spooler is no more...trying respawn...                                       spawned the uWSGI spooler on dir /spooler/mail with pid 15325                          OOOPS the spooler is no more...trying respawn...                                       chdir(): Permission denied [core/spooler.c line 437]                                   
spawned the uWSGI spooler on dir /spooler/stat with pid 15326                          chdir(): Permission denied [core/spooler.c line 437]                                   OOOPS the spooler is no more...trying respawn...                                       spawned the uWSGI spooler on dir /spooler/mail with pid 15327                          
OOOPS the spooler is no more...trying respawn...                                       chdir(): Permission denied [core/spooler.c line 437]                                   spawned the uWSGI spooler on dir /spooler/stat with pid 15328                          chdir(): Permission denied [core/spooler.c line 437]                                   
OOOPS the spooler is no more...trying respawn...                                       spawned the uWSGI spooler on dir /spooler/mail with pid 15329     

Just chown'ing the directories fixes uWSGI startup:

chdir(): Permission denied [core/spooler.c line 437]                                   
spawned the uWSGI spooler on dir /spooler/stat with pid 15352                          chdir(): Permission denied [core/spooler.c line 437]                                   OOOPS the spooler is no more...trying respawn...                                       spawned the uWSGI spooler on dir /spooler/mail with pid 15353                          
OOOPS the spooler is no more...trying respawn...                                       spawned the uWSGI spooler on dir /spooler/stat with pid 15354                                                                                                                                                                                                        
[pid: 20|app: 0|req: 2/26] 93.174.144.106 () {44 vars in 767 bytes} [Mon Aug 27 08:28:13 2018] GET /demande => generated 23849 bytes in 192 msecs (HTTP/1.1 200) 7 headers in 449 bytes (1 switches on core 0)          

As you can see, it then leaves two working spooler processes (in a container, note that uwsgi started as pid 11):

docker exec -it my ps aux                     
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND               
root         1  0.0  0.0   4592   816 ?        Ss   06:19   0:00 /bin/sh -c /usr       
root        10  0.0  0.0   4316   888 ?        S    06:19   0:00 /usr/bin/dumb-i       
uwsgi       11  0.0  0.3 245388 55116 ?        Ss   06:19   0:20 uwsgi --spooler       
uwsgi       15  0.0  0.2 245388 41696 ?        S    06:19   0:00 uwsgi --spooler       
uwsgi       16  0.0  0.3 323876 53696 ?        Sl   06:19   0:00 uwsgi --spooler       
uwsgi       17  0.0  0.3 255824 57684 ?        S    06:19   0:01 uwsgi --spooler       
uwsgi       18  0.0  0.3 328408 58908 ?        Sl   06:19   0:01 uwsgi --spooler       
uwsgi       19  0.0  0.3 330532 61316 ?        Sl   06:19   0:01 uwsgi --spooler       
uwsgi       20  0.0  0.3 252528 53880 ?        S    06:19   0:00 uwsgi --spooler       
uwsgi       21  0.0  0.3 250788 51940 ?        S    06:19   0:00 uwsgi --spooler       
uwsgi       22  0.0  0.3 250788 51940 ?        S    06:19   0:00 uwsgi --spooler       
uwsgi       23  0.0  0.2 245388 41696 ?        S    06:19   0:00 uwsgi --spooler       
uwsgi       24  0.0  0.3 252516 53608 ?        S    06:19   0:00 uwsgi --spooler       
uwsgi       25  0.0  0.2 245528 43252 ?        S    06:19   0:00 uwsgi --spooler       
uwsgi       26  0.0  0.3 251212 52300 ?        S    06:19   0:00 uwsgi --spooler       
uwsgi    15353  0.0  0.2 248056 48096 ?        SN   08:27   0:00 uwsgi --spooler       
uwsgi    15354  0.0  0.2 245388 40796 ?        SN   08:27   0:00 uwsgi --spooler       
root     15371  0.0  0.0  38976  3108 pts/0    Rs+  12:26   0:00 ps aux           
xrmx commented 6 years ago

Please add the uwsgi config

jpic commented 6 years ago

This is how it happens for me, all config in CLI. uwsgi can't write spool files if --uid option is set and a directory of --spooler doesn't exist, because it will create them as root and then write them as user specified with --uid maybe ?

01/09 2018 20:27:09 jpic@jpic ~/work/betagouv/mrs  (jpic)
$ ls -l /tmp/spooler/
total 0

01/09 2018 20:27:12 jpic@jpic ~/work/betagouv/mrs  (jpic)
$ sudo -E uwsgi --uid 1000 --env DJANGO_SETTINGS_MODULE=mrs.settings --env DEBUG=1 --spooler=/tmp/spooler/stat --spooler=/tmp/spooler/mail --spooler-processes 1 --http=:8000 --plugin=python --module=mrs.wsgi:application --honour-stdin --static-map /static=static
[uwsgi-static] added mapping for /static => static
*** Starting uWSGI 2.0.17.1 (64bit) on [Sat Sep  1 20:27:14 2018] ***
compiled with version: 8.1.1 20180531 on 01 August 2018 12:32:44
os: Linux-4.18.5-arch1-1-ARCH #1 SMP PREEMPT Fri Aug 24 12:48:58 UTC 2018
nodename: jpic
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /home/jpic/work/betagouv/mrs
detected binary path: /usr/bin/uwsgi
uWSGI running as root, you can use --uid/--gid/--chroot options
setuid() to 1000
your processes number limit is 62773
your memory page size is 4096 bytes
detected max file descriptor number: 1024
building mime-types dictionary from file /etc/mime.types...1194 entry found
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :8000 fd 4
uwsgi socket 0 bound to TCP address 127.0.0.1:37379 (port auto-assigned) fd 3
Python version: 3.7.0 (default, Jul 15 2018, 10:44:58)  [GCC 8.1.1 20180531]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x559863768290
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 145840 bytes (142 KB) for 1 cores
*** Operational MODE: single process ***
/home/jpic/.local/lib/python3.7/site-packages/psycopg2/__init__.py:144: UserWarning: The psycopg2 wheel package will be renamed from release 2.8; in order to keep installing from binary please use "pip install psycopg2-binary" instead. For details see: <http://initd.org/psycopg/docs/install.html#binary-install-from-pypi>.
  """)
[uwsgi-signal] signum 1 registered (wid: 0 modifier1: 0 target: worker)
[djcall] uwsgi.register_signal(1, mrsstat.models.Stat.objects.create_missing)
[uwsgi-signal] signum 2 registered (wid: 0 modifier1: 0 target: worker)
[djcall] uwsgi.register_signal(2, caisse.models.daily_mail)
[uwsgi-signal] signum 3 registered (wid: 0 modifier1: 0 target: worker)
[djcall] uwsgi.register_signal(3, djcall.models.prune)
[djcall] mrsstat.models.Stat.objects.create_missing() add cron : (0, 2, -1, -1, -1) signal 1
[djcall] caisse.models.daily_mail() add cron : (0, 8, -1, -1, 1) signal 2
[djcall] caisse.models.daily_mail() add cron : (0, 8, -1, -1, 2) signal 2
[djcall] caisse.models.daily_mail() add cron : (0, 8, -1, -1, 3) signal 2
[djcall] caisse.models.daily_mail() add cron : (0, 8, -1, -1, 4) signal 2
[djcall] caisse.models.daily_mail() add cron : (0, 8, -1, -1, 5) signal 2
[djcall] djcall.models.prune(keep=10000) add cron : (0, 4, -1, -1, -1) signal 3
WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x559863768290 pid: 23323 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 23323)
spawned the uWSGI spooler on dir /tmp/spooler/stat with pid 23330
spawned the uWSGI spooler on dir /tmp/spooler/mail with pid 23331
spawned uWSGI worker 1 (pid: 23332, cores: 1)
spawned uWSGI http 1 (pid: 23333)
[pid: 23332|app: 0|req: 1/1] 127.0.0.1 () {40 vars in 740 bytes} [Sat Sep  1 20:27:18 2018] GET /admin/login?next=/admin/ => generated 3901 bytes in 834 msecs (HTTP/1.1 200) 8 headers in 434 bytes (1 switches on core 0)
[pid: 23332|app: 0|req: 2/2] 127.0.0.1 () {42 vars in 842 bytes} [Sat Sep  1 20:27:20 2018] GET /static/webpack_bundles/crudlfap.36aa35a5e45c8baeca60.css => generated 0 bytes in 1 msecs (HTTP/1.1 304) 0 headers in 29 bytes (0 switches on core 0)
[pid: 23332|app: 0|req: 3/3] 127.0.0.1 () {42 vars in 825 bytes} [Sat Sep  1 20:27:20 2018] GET /static/webpack_bundles/crudlfap.36aa35a5e45c8baeca60.js => generated 0 bytes in 3 msecs (HTTP/1.1 304) 0 headers in 29 bytes (0 switches on core 0)
[pid: 23332|app: 0|req: 4/4] 127.0.0.1 () {38 vars in 676 bytes} [Sat Sep  1 20:27:27 2018] GET /contact => generated 4156 bytes in 226 msecs (HTTP/1.1 200) 6 headers in 331 bytes (1 switches on core 0)
Sat Sep  1 20:27:28 2018 - SIGPIPE: writing to a closed pipe/socket/fd (probably the client disconnected) on request /static/webpack_bundles/base.36aa35a5e45c8baeca60.css (ip 127.0.0.1) !!!
Sat Sep  1 20:27:28 2018 - uwsgi_response_sendfile_do(): Broken pipe [core/writer.c line 655] during GET /static/webpack_bundles/base.36aa35a5e45c8baeca60.css (127.0.0.1)
OSError: write error
[pid: 23332|app: 0|req: 5/5] 127.0.0.1 () {38 vars in 731 bytes} [Sat Sep  1 20:27:28 2018] GET /static/webpack_bundles/base.36aa35a5e45c8baeca60.css => generated 0 bytes in 1 msecs via sendfile() (HTTP/1.1 200) 3 headers in 113 bytes (0 switches on core 0)
Sat Sep  1 20:27:29 2018 - SIGPIPE: writing to a closed pipe/socket/fd (probably the client disconnected) on request /static/img/logos/mrs.png (ip 127.0.0.1) !!!
Sat Sep  1 20:27:29 2018 - uwsgi_response_sendfile_do(): Broken pipe [core/writer.c line 655] during GET /static/img/logos/mrs.png (127.0.0.1)
OSError: write error
[pid: 23332|app: 0|req: 6/6] 127.0.0.1 () {38 vars in 660 bytes} [Sat Sep  1 20:27:29 2018] GET /static/img/logos/mrs.png => generated 0 bytes in 0 msecs via sendfile() (HTTP/1.1 200) 3 headers in 113 bytes (0 switches on core 0)
open("/tmp/spooler/mail/uwsgi_spoolfile_on_jpic_23332_1_1155803322_1535826453_368349"): Permission denied [core/spooler.c line 286]
Internal Server Error: /contact
Traceback (most recent call last):
  File "/home/jpic/.local/lib/python3.7/site-packages/django/core/handlers/exception.py", line 34, in inner
    response = get_response(request)
  File "/home/jpic/.local/lib/python3.7/site-packages/django/core/handlers/base.py", line 126, in _get_response
    response = self.process_exception_by_middleware(e, request)
  File "/home/jpic/.local/lib/python3.7/site-packages/django/core/handlers/base.py", line 124, in _get_response
    response = wrapped_callback(request, *callback_args, **callback_kwargs)
  File "/home/jpic/.local/lib/python3.7/site-packages/django/views/generic/base.py", line 68, in view
    return self.dispatch(request, *args, **kwargs)
  File "/home/jpic/.local/lib/python3.7/site-packages/django/views/generic/base.py", line 88, in dispatch
    return handler(request, *args, **kwargs)
  File "/home/jpic/.local/lib/python3.7/site-packages/django/views/generic/edit.py", line 142, in post
    return self.form_valid(form)
  File "/home/jpic/work/betagouv/mrs/src/contact/views.py", line 29, in form_valid
    ).spool('mail')
  File "/home/jpic/src/django-call/djcall/models.py", line 224, in spool
    transaction.on_commit(lambda: uwsgi.spool(arg))
  File "/home/jpic/.local/lib/python3.7/site-packages/django/db/transaction.py", line 100, in on_commit
    get_connection(using).on_commit(func)
  File "/home/jpic/.local/lib/python3.7/site-packages/django/db/backends/base/base.py", line 625, in on_commit
    func()
  File "/home/jpic/src/django-call/djcall/models.py", line 224, in <lambda>
    transaction.on_commit(lambda: uwsgi.spool(arg))
ValueError: unable to spool job
[pid: 23332|app: 0|req: 7/7] 127.0.0.1 () {46 vars in 835 bytes} [Sat Sep  1 20:27:33 2018] POST /contact => generated 18511 bytes in 385 msecs (HTTP/1.1 500) 5 headers in 184 bytes (1 switches on core 0)
^CSIGINT/SIGQUIT received...killing workers...
killing the spooler with pid 23330
killing the spooler with pid 23331
gateway "uWSGI http 1" has been buried (pid: 23333)
s^Cspooler (pid: 23330) annihilated
spooler (pid: 23331) annihilated
worker 1 buried after 1 seconds
goodbye to uWSGI.

01/09 2018 20:27:50 jpic@jpic ~/work/betagouv/mrs  (jpic)
$ ls -l /tmp/spooler/
total 0
drwxr-x--- 2 root root 40 Sep  1 20:27 mail
drwxr-x--- 2 root root 40 Sep  1 20:27 stat

01/09 2018 20:27:53 jpic@jpic ~/work/betagouv/mrs  (jpic)
$ sudo chown 1000 /tmp/spooler/*

01/09 2018 20:27:57 jpic@jpic ~/work/betagouv/mrs  (jpic)
$ sudo -E uwsgi --uid 1000 --env DJANGO_SETTINGS_MODULE=mrs.settings --env DEBUG=1 --spooler=/tmp/spooler/stat --spooler=/tmp/spooler/mail --spooler-processes 1 --http=:8000 --plugin=python --module=mrs.wsgi:application --honour-stdin --static-map /static=static
[uwsgi-static] added mapping for /static => static
*** Starting uWSGI 2.0.17.1 (64bit) on [Sat Sep  1 20:27:59 2018] ***
compiled with version: 8.1.1 20180531 on 01 August 2018 12:32:44
os: Linux-4.18.5-arch1-1-ARCH #1 SMP PREEMPT Fri Aug 24 12:48:58 UTC 2018
nodename: jpic
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /home/jpic/work/betagouv/mrs
detected binary path: /usr/bin/uwsgi
uWSGI running as root, you can use --uid/--gid/--chroot options
setuid() to 1000
your processes number limit is 62773
your memory page size is 4096 bytes
detected max file descriptor number: 1024
building mime-types dictionary from file /etc/mime.types...1194 entry found
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :8000 fd 4
uwsgi socket 0 bound to TCP address 127.0.0.1:41759 (port auto-assigned) fd 3
Python version: 3.7.0 (default, Jul 15 2018, 10:44:58)  [GCC 8.1.1 20180531]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x55a508da1290
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 145840 bytes (142 KB) for 1 cores
*** Operational MODE: single process ***
/home/jpic/.local/lib/python3.7/site-packages/psycopg2/__init__.py:144: UserWarning: The psycopg2 wheel package will be renamed from release 2.8; in order to keep installing from binary please use "pip install psycopg2-binary" instead. For details see: <http://initd.org/psycopg/docs/install.html#binary-install-from-pypi>.
  """)
[uwsgi-signal] signum 1 registered (wid: 0 modifier1: 0 target: worker)
[djcall] uwsgi.register_signal(1, mrsstat.models.Stat.objects.create_missing)
[uwsgi-signal] signum 2 registered (wid: 0 modifier1: 0 target: worker)
[djcall] uwsgi.register_signal(2, caisse.models.daily_mail)
[uwsgi-signal] signum 3 registered (wid: 0 modifier1: 0 target: worker)
[djcall] uwsgi.register_signal(3, djcall.models.prune)
[djcall] mrsstat.models.Stat.objects.create_missing() add cron : (0, 2, -1, -1, -1) signal 1
[djcall] caisse.models.daily_mail() add cron : (0, 8, -1, -1, 1) signal 2
[djcall] caisse.models.daily_mail() add cron : (0, 8, -1, -1, 2) signal 2
[djcall] caisse.models.daily_mail() add cron : (0, 8, -1, -1, 3) signal 2
[djcall] caisse.models.daily_mail() add cron : (0, 8, -1, -1, 4) signal 2
[djcall] caisse.models.daily_mail() add cron : (0, 8, -1, -1, 5) signal 2
[djcall] djcall.models.prune(keep=10000) add cron : (0, 4, -1, -1, -1) signal 3
WSGI app 0 (mountpoint='') ready in 1 seconds on interpreter 0x55a508da1290 pid: 23390 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 23390)
spawned the uWSGI spooler on dir /tmp/spooler/stat with pid 23392
spawned the uWSGI spooler on dir /tmp/spooler/mail with pid 23393
spawned uWSGI worker 1 (pid: 23394, cores: 1)
spawned uWSGI http 1 (pid: 23395)
[spooler] written 42 bytes to file /tmp/spooler/mail/uwsgi_spoolfile_on_jpic_23394_1_1850182442_1535826482_575816
[spooler /tmp/spooler/mail pid: 23393] managing request uwsgi_spoolfile_on_jpic_23394_1_1850182442_1535826482_575816 ...
[djcall] djcall.django.email_send(subject=Nouveau message , body=Nom: oeua Email:, to=['team@example.c, reply_to=['oaeu@aoeu.oaeu) -> Call(id=17).call()
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Subject: =?utf-8?q?Nouveau_message_envoy=C3=A9_depuis_le_site?=
From: from@example.com
To: team@example.com
Reply-To: oaeu@aoeu.oaeu
Date: Sat, 01 Sep 2018 18:28:02 -0000
Message-ID: <153582648264.23393.14403364466480671176@jpic>

Nom: oeua
Email: oaeu@aoeu.oaeu
Message:

aoue
-------------------------------------------------------------------------------
[djcall] djcall.django.email_send(subject=Nouveau message , body=Nom: oeua Email:, to=['team@example.c, reply_to=['oaeu@aoeu.oaeu) -> Call(id=17).call(): success
[spooler /tmp/spooler/mail pid: 23393] done with task uwsgi_spoolfile_on_jpic_23394_1_1850182442_1535826482_575816 after 0 seconds
[pid: 23394|app: 0|req: 1/1] 127.0.0.1 () {46 vars in 835 bytes} [Sat Sep  1 20:28:02 2018] POST /contact => generated 4312 bytes in 372 msecs (HTTP/1.1 200) 6 headers in 331 bytes (1 switches on core 0)
jpic commented 6 years ago

Confirming this also occurred during deployment to production :joy:

pauloxnet commented 5 years ago

I confirm the same issue for me.

I'm using Ubuntu 18.10 and the os package of uwsgi 2.0.17.1 in emperor mode with this configurations https://github.com/20tab/django-uwsgi-template/tree/master/uwsgiconf/locals

If I add the spooler option at the end of global.ini and there's no existing directory, uwsgi create it, but using root as owner:

spooler = %(base)/spooler

I tried to add uid and gid to the configurations with the same results.

The only workaround is to manual create the spooler directory with correct owner before starting the vassal.

Maybe we need something similar to logfile-chown or logfile-chmod but for spoolers.

jpic commented 5 years ago

I think it should just chown them with the uid and gid it will drop privileges to, no need to add a new config imho. If that's ok for you we will open a pull request.

pauloxnet commented 5 years ago

I think your solution can work. 👍

fwjavox commented 4 years ago

Does it work when using immediate-gid/immediate-uid instead of gid/uid?

wynnw commented 2 years ago

I hit this same issue today. Fun ol' timey bug.