Python3 + honour-stdin + (log-master or threaded-logger or req-logger or logger) = no standard output

[marc1n]

It seems that with Python3 options --log-master --honour-stdin (used together) lead to standard output suppression (no expected python traceback at the end of output):

$ uwsgi --http=:1234 --eval='1/0' --log-master --honour-stdin
*** Starting uWSGI 2.0.17.1 (64bit) on [Fri Oct 26 09:52:34 2018] ***
compiled with version: 7.3.0 on 25 October 2018 14:27:36
os: Linux-4.15.0-38-generic #41-Ubuntu SMP Wed Oct 10 10:59:38 UTC 2018
nodename: thorgal
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /tmp
detected binary path: /tmp/env_py3/bin/uwsgi
your processes number limit is 63709
your memory page size is 4096 bytes
detected max file descriptor number: 1024
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :1234 fd 7
uwsgi socket 0 bound to TCP address 127.0.0.1:44887 (port auto-assigned) fd 6
Python version: 3.6.6 (default, Sep 12 2018, 18:26:19)  [GCC 8.0.1 20180414 (experimental) [trunk revision 259383]]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x560845e96180
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 ***

Without these options or with Python2 standard output is printed on console as expected:

Python3:

$ uwsgi --http=:1234 --eval='1/0'
*** Starting uWSGI 2.0.17.1 (64bit) on [Fri Oct 26 10:00:23 2018] ***
compiled with version: 7.3.0 on 25 October 2018 14:27:36
os: Linux-4.15.0-38-generic #41-Ubuntu SMP Wed Oct 10 10:59:38 UTC 2018
nodename: thorgal
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /tmp
detected binary path: /tmp/env_py3/bin/uwsgi
*** WARNING: you are running uWSGI without its master process manager ***
your processes number limit is 63709
your memory page size is 4096 bytes
detected max file descriptor number: 1024
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :1234 fd 4
spawned uWSGI http 1 (pid: 17697)
uwsgi socket 0 bound to TCP address 127.0.0.1:33789 (port auto-assigned) fd 3
Python version: 3.6.6 (default, Sep 12 2018, 18:26:19)  [GCC 8.0.1 20180414 (experimental) [trunk revision 259383]]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x55f3b7fda0e0
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 72920 bytes (71 KB) for 1 cores
*** Operational MODE: single process ***
Traceback (most recent call last):
  File "uwsgi_eval_config", line 1, in <module>
ZeroDivisionError: division by zero

Python2:

$ uwsgi --http=:1234 --eval='1/0' --log-master --honour-stdin
*** Starting uWSGI 2.0.17.1 (64bit) on [Fri Oct 26 09:52:56 2018] ***
compiled with version: 5.4.0 20160609 on 06 September 2018 13:40:59
os: Linux-4.15.0-38-generic #41-Ubuntu SMP Wed Oct 10 10:59:38 UTC 2018
nodename: thorgal
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /tmp
detected binary path: /tmp/env_py2/bin/uwsgi
your processes number limit is 63709
your memory page size is 4096 bytes
detected max file descriptor number: 1024
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :1234 fd 7
uwsgi socket 0 bound to TCP address 127.0.0.1:41327 (port auto-assigned) fd 6
Python version: 2.7.15rc1 (default, Apr 15 2018, 21:51:34)  [GCC 7.3.0]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x1532970
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 ***
Traceback (most recent call last):
  File "uwsgi_eval_config", line 1, in <module>
ZeroDivisionError: integer division or modulo by zero

[marc1n]

The same issue is for combination of --threaded-logger and --honour-stdin (Python3):

$ uwsgi --http=:1234 --eval='1/0' --threaded-logger --honour-stdin
*** Starting uWSGI 2.0.17.1 (64bit) on [Fri Oct 26 10:16:32 2018] ***
compiled with version: 7.3.0 on 25 October 2018 14:27:36
os: Linux-4.15.0-38-generic #41-Ubuntu SMP Wed Oct 10 10:59:38 UTC 2018
nodename: thorgal
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /tmp
detected binary path: /tmp/env_py3/bin/uwsgi
your processes number limit is 63709
your memory page size is 4096 bytes
detected max file descriptor number: 1024
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :1234 fd 7
uwsgi socket 0 bound to TCP address 127.0.0.1:38117 (port auto-assigned) fd 6
Python version: 3.6.6 (default, Sep 12 2018, 18:26:19)  [GCC 8.0.1 20180414 (experimental) [trunk revision 259383]]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x5612a7e05180
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 ***

[marc1n]

Same issue with combination honour-stdin + req-logger (Python3 only):

$ uwsgi --http=:1234 --eval='1/0' --honour-stdin --req-logger=file:/tmp/uwsgi-access.log
*** Starting uWSGI 2.0.17.1 (64bit) on [Fri Oct 26 11:29:39 2018] ***
compiled with version: 7.3.0 on 25 October 2018 14:27:36
os: Linux-4.15.0-38-generic #41-Ubuntu SMP Wed Oct 10 10:59:38 UTC 2018
nodename: thorgal
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /tmp
detected binary path: /tmp/env_py3/bin/uwsgi
your processes number limit is 63709
your memory page size is 4096 bytes
detected max file descriptor number: 1024
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :1234 fd 9
uwsgi socket 0 bound to TCP address 127.0.0.1:34573 (port auto-assigned) fd 8
Python version: 3.6.6 (default, Sep 12 2018, 18:26:19)  [GCC 8.0.1 20180414 (experimental) [trunk revision 259383]]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x55d0d6a3a2f0
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 ***

[marc1n]

Same issue with combination honour-stdin + logger=fd:0 (Python3 only):

$ uwsgi --http=:1234 --eval='1/0' --honour-stdin --logger=fd:0
*** Starting uWSGI 2.0.17.1 (64bit) on [Fri Oct 26 11:33:28 2018] ***
compiled with version: 7.3.0 on 25 October 2018 14:27:36
os: Linux-4.15.0-38-generic #41-Ubuntu SMP Wed Oct 10 10:59:38 UTC 2018
nodename: thorgal
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 4
current working directory: /tmp
detected binary path: /tmp/env_py3/bin/uwsgi
your processes number limit is 63709
your memory page size is 4096 bytes
detected max file descriptor number: 1024
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :1234 fd 7
uwsgi socket 0 bound to TCP address 127.0.0.1:36665 (port auto-assigned) fd 6
Python version: 3.6.6 (default, Sep 12 2018, 18:26:19)  [GCC 8.0.1 20180414 (experimental) [trunk revision 259383]]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x56296ccb32e0
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 ***

[marc1n]

The problem is still valid (in uWSGI 2.0.17.1 and the latest 2.0.19.1) but only in Python 3.6.x and Python 3.7.x.

In Python 3.8 (I've tested 3.8.6), uWSGI 2.0.17.1/2.0.19.1 works OK (traceback is printed on console) .

[marc1n]

I've found the workaround for Python 3.6 and 3.7: disabling output buffering in Python (setting environment variable: export PYTHONUNBUFFERED=1).

It works for uWSGI 2.0.17.1/2.0.19.1.