uwsgi logging to file causes BlockingIOError with Python app

[lcosmin]

Not sure if this is a bug, misconfiguration or simply how things should work. I've got an wsgi app which produces a lot of output. When logto is enabled to a file, sometimes I get a BlockingIOError from the Python logger.

Using uwsgi 2.0.20, python 3.8.

Here's some test code, whose only purpose is to produce lots of log messages.

import logging
import time


logging.basicConfig(level=logging.DEBUG)

log = logging.getLogger()


def main():

    while True:
        for i in range(1000000):
            log.debug("hello, world")
        time.sleep(2)


main()
app = None

The XML configuration for uwsgi is:

<uwsgi>
    <socket>/tmp/test.sock</socket>
    <thunder-lock />
    <disable-logging />
    <logto>/var/log/test.log</logto>
    <log-maxsize>1073741824</log-maxsize>
    <log-backupname>/var/log/test.log.1</log-backupname>
    <log-master />
    <log-reopen />
    <log-4xx />
    <log-5xx />
    <log-date />
    <log-zero />
    <logfile-chown />
    <ignore-sigpipe />
    <master />
    <lazy-apps />
    <no-default-app />
    <need-app />
    <no-orphans />
    <processes>1</processes>
    <single-interpreter />
    <listen>128</listen>
    <module>work.test</module>
    <callable>app</callable>
</uwsgi>

Running the code in uWSGI will eventually produce errors like below:

--- Logging error ---
DEBUG:root:hello, world
--- Logging error ---
DEBUG:root:hello, world
--- Logging error ---
DEBUG:root:hello, world
--- Logging error ---
Traceback (most recent call last):
  File "/usr/lib/python3.8/logging/__init__.py", line 1088, in emit
    stream.write(msg + self.terminator)
BlockingIOError: [Errno 11] write could not complete without blocking
Call stack:
  File "<frozen importlib._bootstrap>", line 991, in _find_and_load
  File "<frozen importlib._bootstrap>", line 975, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 671, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 848, in exec_module
  File "<frozen importlib._bootstrap>", line 219, in _call_with_frames_removed
  File "/usr/lib/python3/dist-packages/work/test.py", line 18, in <module>
    main()
  File "/usr/lib/python3/dist-packages/work/test.py", line 14, in main
    log.debug("hello, world")
Message: 'hello, world'
Arguments: ()
DEBUG:root:hello, world
DEBUG:root:hello, world

Is there anything I can do to prevent this from happening?

[sindhujit1]

I have the same issue . Noticed it today in our production server. Any help on this ? Using uwsgi 2.0.20, python 3.8. Did you find any fix for this @lcosmin ?

[lcosmin]

Did you find any fix for this @lcosmin ?

Yes, I'm not letting uwsgi manage my log file anymore, and I only log to stdout

[sindhujit1]

Can you please share how you are logging to stdout ? Is there a central file where you see the logs? Is app still running in wsgi though ?

[sindhujit1]

Can you please share how you are logging to stdout ? Is there a central file where you see the logs? Is app still running in wsgi though ? @lcosmin