unbit / uwsgi

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

SystemError when sys.exc_info() passed to start_response #2278

Open jackkordas opened 3 years ago

jackkordas commented 3 years ago

This seems specific to python3.

$ cat test_500.wsgi 
#!/usr/bin/env python
import os
import sys

HELLO_WORLD = b"Hello world!\n"

def simple_app(environ, start_response):
    """Simplest possible application object"""
    try:
        status = '200 OK'
        response_headers = [('Content-type', 'text/plain')]
        #start_response(status, response_headers)
        raise Exception('testing')
        return [HELLO_WORLD]
    except:
        body = b'Hello exception!\n'
        status = '500 Internal Server Errror'
        headers = [('Content-type', 'text/plain')]
        start_response(status, headers, sys.exc_info())
        return [body]

application = simple_app

$  uwsgi --http :9090 --wsgi-file test_500.wsgi 
*** Starting uWSGI 2.0.18 (64bit) on [Fri Jan 15 15:37:32 2021] ***
compiled with version: 4.2.1 Compatible Apple LLVM 10.0.0 (clang-1000.11.45.5) on 25 September 2019 17:55:47
os: Darwin-17.7.0 Darwin Kernel Version 17.7.0: Fri Oct 30 13:34:27 PDT 2020; root:xnu-4570.71.82.8~1/RELEASE_X86_64
nodename: ip-192-168-1-175.ec2.internal
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 8
current working directory: /Users/kordas/today/play/uwsgi
detected binary path: /Users/kordas/today/play/uwsgi/venv3/bin/uwsgi
*** WARNING: you are running uWSGI without its master process manager ***
your processes number limit is 1418
your memory page size is 4096 bytes
detected max file descriptor number: 256
lock engine: OSX spinlocks
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :9090 fd 4
spawned uWSGI http 1 (pid: 38190)
uwsgi socket 0 bound to TCP address 127.0.0.1:64756 (port auto-assigned) fd 3
Python version: 3.7.5 (default, Nov  1 2019, 02:16:38)  [Clang 10.0.0 (clang-1000.11.45.5)]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x7fda2ac04ab0
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 72888 bytes (71 KB) for 1 cores
*** Operational MODE: single process ***
WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x7fda2ac04ab0 pid: 38189 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI worker 1 (and the only) (pid: 38189, cores: 1)
Traceback (most recent call last):
  File "test_500.wsgi", line 13, in simple_app
    raise Exception('testing')
Exception: testing

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "test_500.wsgi", line 19, in simple_app
    start_response(status, headers, sys.exc_info())
SystemError: <built-in function uwsgi_spit> returned a result with an error set
[pid: 38189|app: 0|req: 1/1] 127.0.0.1 () {28 vars in 311 bytes} [Fri Jan 15 15:37:49 2021] GET / => generated 0 bytes in 0 msecs (HTTP/1.1 500) 1 headers in 65 bytes (1 switches on core 0)

As a result, 'Hello exception!' is not seen as part of the response (no body).

xrmx commented 3 years ago

Have you tried latest stable release?

jackkordas commented 3 years ago

This is on 2.0.19.1

xrmx commented 3 years ago

What you pasted says otherwise though:

$  uwsgi --http :9090 --wsgi-file test_500.wsgi 
*** Starting uWSGI 2.0.18 (64bit) on [Fri Jan 15 15:37:32 2021] ***
jackkordas commented 3 years ago

Sorry, I've run in in several different environments to check if there was a recent regression or to see if I was missing something obvious.

Here's one from a source build with the 2.0.19.1 tag checked out

uwsgi/uwsgi --http :9090 --wsgi-file stackoverflow.wsgi 
*** Starting uWSGI 2.0.19.1 (64bit) on [Mon Jan 18 18:10:37 2021] ***
compiled with version: 7.5.0 on 15 January 2021 20:53:44
os: Linux-5.4.0-1032-aws #33~18.04.1-Ubuntu SMP Thu Dec 10 08:19:06 UTC 2020
nodename: gcs54-test-env
machine: x86_64
clock source: unix
detected number of CPU cores: 2
current working directory: /home/ubuntu/uwsgi
detected binary path: /home/ubuntu/uwsgi/uwsgi/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
*** WARNING: you are running uWSGI without its master process manager ***
your processes number limit is 15623
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 :9090 fd 4
spawned uWSGI http 1 (pid: 3696)
uwsgi socket 0 bound to TCP address 127.0.0.1:38307 (port auto-assigned) fd 3
Python version: 3.6.9 (default, Oct  8 2020, 12:12:24)  [GCC 8.4.0]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x562876142980
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 72904 bytes (71 KB) for 1 cores
*** Operational MODE: single process ***
WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x562876142980 pid: 3695 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI worker 1 (and the only) (pid: 3695, cores: 1)
Traceback (most recent call last):
  File "stackoverflow.wsgi", line 13, in simple_app
    raise Exception('testing')
Exception: testing

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "stackoverflow.wsgi", line 19, in simple_app
    start_response(status, headers, sys.exc_info())
SystemError: <built-in function uwsgi_spit> returned a result with an error set
[pid: 3695|app: 0|req: 1/1] 127.0.0.1 () {28 vars in 296 bytes} [Mon Jan 18 18:11:34 2021] GET / => generated 0 bytes in 88 msecs (HTTP/1.1 500) 1 headers in 65 bytes (0 switches on core 0)

and one from pypy (pip install)

$ uwsgi --http :9090 --wsgi-file s0.wsgi 
*** Starting uWSGI 2.0.19.1 (64bit) on [Mon Jan 18 18:18:26 2021] ***
compiled with version: 5.4.0 20160609 on 23 July 2020 15:03:23
os: Linux-4.4.0-1110-aws #121-Ubuntu SMP Fri Jun 12 04:21:59 UTC 2020
nodename: jack-dev
machine: x86_64
clock source: unix
detected number of CPU cores: 2
current working directory: /home/koa/tmp
detected binary path: /opt/venv-koa/bin/uwsgi
!!! no internal routing support, rebuild with pcre support !!!
*** WARNING: you are running uWSGI without its master process manager ***
your processes number limit is 7793
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 :9090 fd 4
spawned uWSGI http 1 (pid: 2520)
uwsgi socket 0 bound to TCP address 127.0.0.1:44276 (port auto-assigned) fd 3
Python version: 3.5.2 (default, Jul 17 2020, 14:04:10)  [GCC 5.4.0 20160609]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0xf97970
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 ***
WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0xf97970 pid: 2519 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI worker 1 (and the only) (pid: 2519, cores: 1)
Traceback (most recent call last):
  File "s0.wsgi", line 13, in simple_app
    raise Exception('testing')
Exception: testing

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "s0.wsgi", line 19, in simple_app
    start_response(status, headers, sys.exc_info())
SystemError: <built-in function uwsgi_spit> returned a result with an error set
[pid: 2519|app: 0|req: 1/1] 127.0.0.1 () {28 vars in 290 bytes} [Mon Jan 18 18:18:30 2021] GET / => generated 0 bytes in 0 msecs (HTTP/1.1 500) 1 headers in 65 bytes (0 switches on core 0)
Tugzrida commented 3 years ago

I've experienced the same behaviour with 2.0.19.1 and python 3.8.5: including the third parameter to start_response raises a SystemError and prevents the response body from being processed.

jeremylowery commented 2 years ago

I've also experienced the same behavior with 2.0.18 and python 3.8.10. This problem does not allow an exception handler to return back a friendly error message to the browser.

muravjov commented 1 year ago

same here, my env is

$ env/bin/uwsgi --version
2.0.22
$ env/bin/python -V
Python 3.11.5
$ uname -a
Linux ubuntu 5.4.0-1098-kvm #104-Ubuntu SMP Fri Aug 18 09:21:53 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux
$ cat /etc/issue
Ubuntu 20.04 LTS \n \l

I hoped it fails in Macos only, but it fails in Linux, too

muravjov commented 1 year ago

This seems specific to python3.

$ cat test_500.wsgi 
#!/usr/bin/env python
import os
import sys

HELLO_WORLD = b"Hello world!\n"

def simple_app(environ, start_response):
    """Simplest possible application object"""
    try:
        status = '200 OK'
        response_headers = [('Content-type', 'text/plain')]
        #start_response(status, response_headers)
        raise Exception('testing')
        return [HELLO_WORLD]
    except:
        body = b'Hello exception!\n'
        status = '500 Internal Server Errror'
        headers = [('Content-type', 'text/plain')]
        start_response(status, headers, sys.exc_info())
        return [body]

application = simple_app

$  uwsgi --http :9090 --wsgi-file test_500.wsgi 
*** Starting uWSGI 2.0.18 (64bit) on [Fri Jan 15 15:37:32 2021] ***
compiled with version: 4.2.1 Compatible Apple LLVM 10.0.0 (clang-1000.11.45.5) on 25 September 2019 17:55:47
os: Darwin-17.7.0 Darwin Kernel Version 17.7.0: Fri Oct 30 13:34:27 PDT 2020; root:xnu-4570.71.82.8~1/RELEASE_X86_64
nodename: ip-192-168-1-175.ec2.internal
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 8
current working directory: /Users/kordas/today/play/uwsgi
detected binary path: /Users/kordas/today/play/uwsgi/venv3/bin/uwsgi
*** WARNING: you are running uWSGI without its master process manager ***
your processes number limit is 1418
your memory page size is 4096 bytes
detected max file descriptor number: 256
lock engine: OSX spinlocks
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :9090 fd 4
spawned uWSGI http 1 (pid: 38190)
uwsgi socket 0 bound to TCP address 127.0.0.1:64756 (port auto-assigned) fd 3
Python version: 3.7.5 (default, Nov  1 2019, 02:16:38)  [Clang 10.0.0 (clang-1000.11.45.5)]
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x7fda2ac04ab0
your server socket listen backlog is limited to 100 connections
your mercy for graceful operations on workers is 60 seconds
mapped 72888 bytes (71 KB) for 1 cores
*** Operational MODE: single process ***
WSGI app 0 (mountpoint='') ready in 0 seconds on interpreter 0x7fda2ac04ab0 pid: 38189 (default app)
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI worker 1 (and the only) (pid: 38189, cores: 1)
Traceback (most recent call last):
  File "test_500.wsgi", line 13, in simple_app
    raise Exception('testing')
Exception: testing

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "test_500.wsgi", line 19, in simple_app
    start_response(status, headers, sys.exc_info())
SystemError: <built-in function uwsgi_spit> returned a result with an error set
[pid: 38189|app: 0|req: 1/1] 127.0.0.1 () {28 vars in 311 bytes} [Fri Jan 15 15:37:49 2021] GET / => generated 0 bytes in 0 msecs (HTTP/1.1 500) 1 headers in 65 bytes (1 switches on core 0)

As a result, 'Hello exception!' is not seen as part of the response (no body).

I confirm with the latest stable release:

$ cat ./test_500.wsgi
#!/usr/bin/env python
import os
import sys

HELLO_WORLD = b"Hello world!\n"

def simple_app(environ, start_response):
    """Simplest possible application object"""
    try:
        status = '200 OK'
        response_headers = [('Content-type', 'text/plain')]
        #start_response(status, response_headers)
        raise Exception('testing')
        return [HELLO_WORLD]
    except:
        body = b'Hello exception!\n'
        status = '500 Internal Server Errror'
        headers = [('Content-type', 'text/plain')]
        start_response(status, headers, sys.exc_info())
        return [body]

application = simple_app

$ uwsgi --http :9777 --wsgi-file test_500.wsgi
*** Starting uWSGI 2.0.22 (64bit) on [Wed Oct  4 09:50:37 2023] ***
compiled with version: 9.4.0 on 04 October 2023 07:17:43
os: Linux-5.4.0-1098-kvm #104-Ubuntu SMP Fri Aug 18 09:21:53 UTC 2023
nodename: ubuntu
...
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI worker 1 (and the only) (pid: 188146, cores: 1)

Traceback (most recent call last):
  File "test_500.wsgi", line 13, in simple_app
    raise Exception('testing')
Exception: testing

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "test_500.wsgi", line 19, in simple_app
    start_response(status, headers, sys.exc_info())
SystemError: <built-in function uwsgi_spit> returned a result with an exception set
[pid: 188146|app: 0|req: 1/1] 127.0.0.1 () {28 vars in 288 bytes} [Wed Oct  4 09:50:57 2023] GET / => generated 0 bytes in 0 msecs (HTTP/1.1 500) 1 headers in 65 bytes (0 switches on core 0
)
muravjov commented 1 year ago

I broke my gdb open and wandered around py_uwsgi_spit. It turned out it causes _PyErr_Occurred() to be true in case of startresponse(, _, sys.exc_info()) => SystemError.

I am not an expert but seems like PyErr_Restore() doesn't work well in Py3, is the root cause:

            Py_INCREF(exc_type);
            Py_INCREF(exc_val);
            Py_INCREF(exc_tb);
            // in this way, error will be reported to the log
            PyErr_Restore(exc_type, exc_val, exc_tb); // <=====

see https://github.com/unbit/uwsgi/blob/9d57149041c35498a41f2226053884f102bcdc57/plugins/python/wsgi_headers.c#L37

So, my workaround is as follows:

$ diff -Naur test_500.wsgi_orig test_500.wsgi
--- test_500.wsgi_orig  2023-10-04 14:30:33.830243184 +0000
+++ test_500.wsgi       2023-10-04 14:32:21.891442173 +0000
@@ -16,7 +16,12 @@
         body = b'Hello exception!\n'
         status = '500 Internal Server Errror'
         headers = [('Content-type', 'text/plain')]
-        start_response(status, headers, sys.exc_info())
+
+        if environ.get("uwsgi.version"):
+            start_response(status, headers)
+        else:
+            start_response(status, headers, sys.exc_info())
+
         return [body]

 application = simple_app
muravjov commented 1 year ago

btw, how other wsgi servers act:


* gunicorn: does nothing with exc_info
def start_response(self, status, headers, exc_info=None):
    if exc_info:
        try:
            if self.status and self.headers_sent:
                util.reraise(exc_info[0], exc_info[1], exc_info[2])
        finally:
            exc_info = None
    elif self.status is not None:
        raise AssertionError("Response headers already set!")

    self.status = status

    # get the status code from the response here so we can use it to check
    # the need for the connection header later without parsing the string
    # each time.
    try:
        self.status_code = int(self.status.split()[0])
    except ValueError:
        self.status_code = None

    self.process_headers(headers)
    self.chunked = self.is_chunked()
    return self.write