Python 3.12 has fatal error

onegreyonewhite commented 11 months ago

Fatal Python error: PyImport_AppendInittab: PyImport_AppendInittab() may not be called after Py_Initialize()

I hoped that it was problem in old version but it still fails.

https://github.com/lincolnloop/pyuwsgi-wheels/issues/20

Looks like that in this part of code PyImport_AppendInittab called before Py_Initialize.

xrmx commented 11 months ago

Could you please provide an uwsgi invocation to reproduce it? thanks

onegreyonewhite commented 11 months ago

@xrmx

Could you please provide an uwsgi invocation to reproduce it? thanks

It's hard because uwsgi in deep abstraction level. But this string of execution:

/usr/local/bin/uwsgi --set-ph=program_name=deigmata_courier --set-ph=lib_name=deigmata --set-ph=api_path=api --set-ph=vstutils_version=5.8.10 --env=DJANGO_SETTINGS_MODULE=deigmata_courier.settings --python-worker-override=/usr/local/lib/python3.12/dist-packages/vstutils/asgi_worker.py --socket=0.0.0.0:8080 --ini=/usr/local/lib/python3.12/dist-packages/deigmata/settings.ini --ini=/etc/vstutils/settings.ini --ini=/etc/deigmata/settings.ini /usr/local/lib/python3.12/dist-packages/vstutils/web.ini --ini -

I'll try to reproduce it without all abstractions.

onegreyonewhite commented 11 months ago

@xrmx simple fastapi app.

fastapi_app.py

from fastapi import FastAPI

application = FastAPI()

@application.get('/test')
def test():
    return "Hello World!"

Command: uwsgi --module fastapi_app:application --http :8080

Output:

*** Starting uWSGI 2.0.23 (64bit) on [Tue Nov  7 13:48:29 2023] ***
compiled with version: 10.2.1 20210130 (Red Hat 10.2.1-11) on 07 November 2023 19:10:56
os: Linux-6.2.0-36-generic #37~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Mon Oct  9 15:34:04 UTC 2
nodename: grey-notebook
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 12
current working directory: /home/grey/Projects/vst/quick
detected binary path: /home/grey/.pyenv/versions/3.12.0/bin/python3.12
*** WARNING: you are running uWSGI without its master process manager ***
your processes number limit is 255100
your memory page size is 4096 bytes
detected max file descriptor number: 1048576
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uWSGI http bound on :8080 fd 4
spawned uWSGI http 1 (pid: 1592573)
uwsgi socket 0 bound to TCP address 127.0.0.1:35307 (port auto-assigned) fd 3
Python version: 3.12.0 (main, Oct  3 2023, 12:55:49) [GCC 11.4.0]
--- Python VM already initialized ---
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x7f4f3e2c0e30
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 ***
Fatal Python error: PyImport_AppendInittab: PyImport_AppendInittab() may not be called after Py_Initialize()
Python runtime state: initialized

Current thread 0x00007f4f3e3a6b80 (most recent call first):
  File "/home/grey/Projects/vst/quick/test_312/bin/uwsgi", line 8 in <module>

Extension modules: pyuwsgi (total: 1)

Lalufu commented 10 months ago

Do you have the python module built into the main binary?

@xrmx There's a second call to PyImport_AppendInittab from init_uwsgi_embedded_module in plugins/python/python_plugin.c which I guess is only used if the module is built in? I'm not sure what the call order is, and if this is still needed (clearly we've called Py_Initialize already, and the first PyImport_AppendInittab call is before it)

Tenzer commented 10 months ago

We are seeing the same error when trying to upgrade to Python 3.12. We are using uWSGI provided via the pyuwsgi package: https://pypi.org/project/pyuwsgi/.

Lalufu commented 10 months ago

Would you be able to test from a branch instead of a normal source tarball?

Tenzer commented 10 months ago

Yes, if that can help get this solved :)

Lalufu commented 10 months ago

After staring at this for a while, and figuring out how to build pyuwsgi in the first place, I... can't reproduce this.

I did:

Checkout https://github.com/lincolnloop/pyuwsgi-wheels at the 2.0.23 tag
Build the wheel on a Fedora 39 with python 3.12.0 installed following what the github actions do
```
./patch-uwsgi-packaging.sh uwsgi
python3.12 -mpip wheel ./uwsgi --wheel-dir foo --no-deps
```
Install the resulting wheel into a new venv
Run the example application above

And uwsgi starts up cleanly. I then get an error when actually requesting the /test url, but that's no longer a python plugin problem:

TypeError: FastAPI.__call__() missing 1 required positional argument: 'send'

The only possible explanation I have is that for some reason the wheel that was built in the github pipeline was somehow not built against 3.12, or a very early version of 3.12, that didn't trigger the version check in uwsgi, and took the pre-3.12 code path?

ipmb commented 10 months ago

@Lalufu I maintain the wheels and have been trusting cibuildwheel to do the right thing, but digging into the logs on that build, I think you might be right. I found this:

CleanShot 2023-12-07 at 13 34 14

I upgraded cibuildwheel and am running a new build now. If that looks better, I'll publish a 2.0.23.post0 version to PyPI.

Lalufu commented 10 months ago

Appreciate the test.

This should be good, though, we test for (PY_VERSION_HEX >= 0x030c0000) and 3.12.0rc1 is 0x030C00C1, which is clearly greater.

Tenzer commented 10 months ago

I can confirm that I am only able to reproduce the issue with the pyuwsgi PyPI package. If I instead use the uwsgi package and build uWSGI myself, then there's no problem.

A reproduction case for this can be found here: https://gist.github.com/Tenzer/bf8b018d823d0f5c4f291b464444c4cd. uWSGI fails to start with both amd64 and arm64. If line 3 in Dockerfile instead is changed to install uwsgi==2.0.23 then it works fine.

Tenzer commented 10 months ago

@ipmb I have just tried to download the dist files from the build and installed the wheel from the downloaded file in the Docker image, and it still fails in the same way, both for amd64 and arm64.

ipmb commented 10 months ago

I'm testing some different ways to build, but this should come pretty close to mirroring what the GHA is doing:

git clone git@github.com:lincolnloop/pyuwsgi-wheels.git
cd pyuwsgi-wheels
git submodule update --init

python -m venv --prompt . --upgrade-deps .venv
. .venv/bin/activate
pip install cibuildwheel

export CIBW_ENVIRONMENT='APPEND_VERSION="" UWSGI_PROFILE=pyuwsginossl'
export CIBW_BEFORE_ALL="./patch-uwsgi-packaging.sh uwsgi"
export CIBW_BEFORE_BUILD_LINUX='./pre_build.sh && (yum install -y zlib-devel || apk add zlib-dev)'
export CIBW_BUILD=cp312-manylinux_x86_64

cibuildwheel --platform linux --output-dir dist uwsgi

You should end up with Python 3.12 wheel in the dist directory

ipmb commented 10 months ago

I'm stumped on this. I was able to build the wheel successfully locally using cibuildwheel, but the ones built on GHA aren't working. Is it possible to output what PY_VERSION_HEX is so we can debug further?

Lalufu commented 10 months ago

Try applying this to the uWSGI tree pyuwsgi before building?

diff --git a/plugins/python/python_plugin.c b/plugins/python/python_plugin.c index c69abc18..fcfa66b5 100644 --- a/plugins/python/python_plugin.c +++ b/plugins/python/python_plugin.c @@ -222,6 +222,18 @@ int uwsgi_python_init() { uwsgi_log_initial("Python version: %.*s %s\n", pyversion-Py_GetVersion(), Py_GetVersion(), Py_GetCompiler()+1); }

uwsgi_log_initial("Built against 0x%08x\n", PY_VERSION_HEX); +#ifdef UWSGI_PY311
uwsgi_log_initial("UWSGI_PY11 defined\n"); +#else
uwsgi_log_initial("UWSGI_PY11 NOT defined\n"); +#endif +#ifdef UWSGI_PY312
uwsgi_log_initial("UWSGI_PY12 defined\n"); +#else
uwsgi_log_initial("UWSGI_PY12 NOT defined\n"); +#endif
if (Py_IsInitialized()) { uwsgi_log("--- Python VM already initialized ---\n"); PyGILState_Ensure();

Lalufu commented 10 months ago

uwsgi-version-debug.txt Proper attachment

ipmb commented 10 months ago

I have wheels built here with the patch applied. I tried running them and am not seeing anything new in the output. Maybe you could take a look @Lalufu ?

Lalufu commented 10 months ago

You should see output when using the wheel, not during the build. See the fastapi_app.py example a bit further up.

Where can I find the artifacts (binary wheels) from the last pipeline run?

ipmb commented 10 months ago

Yes, I ran the example with the wheels from the build and didn't see (or missed) any additional output.

You can find the wheels with the debugging patch applied here, https://github.com/lincolnloop/pyuwsgi-wheels/actions/runs/7144198124 CleanShot 2023-12-08 at 12 52 26

Lalufu commented 10 months ago

Found them, thanks.

I installed pyuwsgi-2.0.23.post0-cp311-cp311-manylinux_2_17_x86_64.manylinux2014_x86_64.whl from that into a new venv, and got the following:

[...]
Python version: 3.11.6 (main, Oct  3 2023, 00:00:00) [GCC 13.2.1
20230728 (Red Hat 13.2.1-1)]
Built against 0x030711f0
UWSGI_PY11 NOT defined
UWSGI_PY12 NOT defined
--- Python VM already initialized ---
[...]

The runtime python is a 3.11.6 (as expected), but the binary module was built against a 3.7.17. Which certainly isn't a 3.11.

I'm not sure what's going on in that build system, but it's not doing what it's supposed to do. I'm somewhat surprised this isn't blowing up more violently.

Lalufu commented 10 months ago

What I think is happening is that the build pipeline contains python binaries of the proper version (like 3.12.0rc1) and is using these to run the pip wheel process, but only contains development C headers for 3.7.11, and that's what's getting picked up by uWSGI.

I'm not familiar enough with this to know how to fix this, though.

ipmb commented 10 months ago

I opened an issue upstream to try to get some more details on how to debug. cibuildwheel is used by a bunch of big Python projects, so I'm guessing there is something we can change about how we're using it to get things working.

ipmb commented 10 months ago

@Lalufu based on the feedback here https://github.com/pypa/cibuildwheel/issues/1693#issuecomment-1851024968

Is there a way I can output the uWSGI Python version in a command that doesn't start a server that runs forever? Currently I'm using uwsgi --help to do a basic smoke test on the built binary. Is there something I can run which will exit successfully after it starts and print the Python version?

xrmx commented 10 months ago

The include paths should be a good hint on which headers uwsgi is building against. See CFLAGS in plugins/pyuwsgi/uwsgiplugin.py.

Lalufu commented 10 months ago

What might work is running

~/venv/pyuwsgi/bin/uwsgi --module foo --need-app --http :8080

(or whereever you installed the wheel), making sure that foo doesn't actually exist in your path. This will start uwsgi, initialize the python interpreter (showing the log messages about the version it was built against if you used the patch), and then die because it can't find foo.

ipmb commented 10 months ago

Could I get confirmation that the wheels in the dist Artifact here are working for folks? https://github.com/lincolnloop/pyuwsgi-wheels/actions/runs/7201594896

If so, I can clean things up and get this merged and published.

chrisjsimpson commented 9 months ago

Could I get confirmation that the wheels in the dist Artifact here are working for folks?

@ipmb I've had a shot at that just now and here's my findings as I'm also hitting the PyImport_AppendInittab() may not be called after Py_Initialize() condition on Python 3.12.0 hope the following helps reproduce.

I see this may be related to the upstream https://github.com/pypa/cibuildwheel/issues/1693 but posting here to help add detail.

Additional Context: I'm experimenting with using pyuwsgi instead of uwsgi because I can't work out how to get rye to build packages which don't distribute wheels

Steps followed:

Reproducing the issue:

python --version
Python 3.12.0

With

pyuwsgi --version
2.0.23

uwsgi --ini emperor.ini --uid example

uwsgi[58364]: *** Starting uWSGI 2.0.23 (64bit) on [Mon Jan  1 22:23:51 2024] *** 
uwsgi[58364]: compiled with version: 10.2.1 20210130 (Red Hat 10.2.1-11) on 07 November 2023 19:10:56
uwsgi[58364]: os: Linux-5.15.0-91-generic #101-Ubuntu SMP Tue Nov 14 13:30:08 UTC 2023
uwsgi[58364]: nodename: example.com
uwsgi[58364]: machine: x86_64
uwsgi[58364]: clock source: unix
uwsgi[58364]: pcre jit disabled
uwsgi[58364]: detected number of CPU cores: 8
uwsgi[58364]: current working directory: /home/example/www/api.example.com
uwsgi[58364]: detected binary path: /home/example/.rye/py/cpython@3.12.0/install/bin/python3.12
uwsgi[58364]: your processes number limit is 255850
uwsgi[58364]: your memory page size is 4096 bytes
uwsgi[58364]: detected max file descriptor number: 1024
uwsgi[58364]: lock engine: pthread robust mutexes
uwsgi[58364]: thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi[58364]: uWSGI fastrouter bound on 127.0.0.1:8001 fd 4
uwsgi[58364]: uWSGI fastrouter subscription server bound on /tmp/sock2 fd 5
uwsgi[58364]: Python version: 3.12.0 (main, Oct  3 2023, 01:27:23) [Clang 17.0.1 ]
uwsgi[58364]: --- Python VM already initialized --- 
uwsgi[58364]: Python main interpreter initialized at 0x7fe01f427560
uwsgi[58364]: python threads support enabled
uwsgi[58364]: your mercy for graceful operations on workers is 60 seconds
uwsgi[58364]: *** Operational MODE: no-workers *** 
uwsgi[58364]: Fatal Python error: PyImport_AppendInittab: PyImport_AppendInittab() may not be called after Py_Initialize()
uwsgi[58364]: Python runtime state: initialized
uwsgi[58364]: Current thread 0x00007fe01d8cf740 (most recent call first):
uwsgi[58364]:   File "/home/example/test/.venv/bin/uwsgi", line 8 in <module>
uwsgi[58364]: Extension modules: pyuwsgi (total: 1)

Switching to Python 3.10, I'm able to successfully install & mostly* run `pyuwsgi-2.0.23`

Now testing the build artefacts from https://github.com/lincolnloop/pyuwsgi-wheels/actions/runs/7201594896

(Note this time the error "Fatal Python error: PyImport_AppendInittab: PyImport_AppendInittab() may not be called after Py_Initialize()" does not occur.

python --version
Python 3.10.13
pip install dist/pyuwsgi-2.0.23.post0-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl

*Which successfully runs (ignoring the --include error)

uwsgi --ini emperor.ini --uid example

example.com systemd[1]: Starting Example uWSGI Emperor...                                                                                                                                     example.com uwsgi[71075]: [uWSGI] getting INI configuration from emperor.ini       
example.com uwsgi[71075]: *** Starting uWSGI 2.0.23 (64bit) on [Mon Jan  1 23:11:11 2024] ***                                                                                                 example.com uwsgi[71075]: compiled with version: 10.2.1 20210130 (Red Hat 10.2.1-11) on 13 December 2023 22:07:31       
example.com uwsgi[71075]: os: Linux-5.15.0-91-generic #101-Ubuntu SMP Tue Nov 14 13:30:08 UTC 2023                                                                                            example.com uwsgi[71075]: nodename: example.com          
example.com uwsgi[71075]: machine: x86_64                                                                                                                                                     example.com uwsgi[71075]: clock source: unix       
example.com uwsgi[71075]: pcre jit disabled                                                                                                                                                   example.com uwsgi[71075]: detected number of CPU cores: 8       
example.com uwsgi[71075]: current working directory: /home/example/www/api.example.com                                                                                                        example.com uwsgi[71075]: detected binary path: /usr/bin/python3.10       
example.com uwsgi[71075]: your processes number limit is 255850                                                                                                                               example.com uwsgi[71075]: your memory page size is 4096 bytes       
example.com uwsgi[71075]: detected max file descriptor number: 1024                                                                                                                           example.com uwsgi[71075]: lock engine: pthread robust mutexes       
example.com uwsgi[71075]: thunder lock: disabled (you can enable it with --thunder-lock)
example.com uwsgi[71075]: uWSGI fastrouter bound on 127.0.0.1:8001 fd 4       
example.com uwsgi[71075]: uWSGI fastrouter subscription server bound on /tmp/sock2 fd 5
example.com uwsgi[71075]: Python version: 3.10.12 (main, Nov 20 2023, 15:14:05) [GCC 11.4.0]
example.com uwsgi[71075]: --- Python VM already initialized ---                    
example.com uwsgi[71075]: Python main interpreter initialized at 0x562dd1e0dfc0
example.com uwsgi[71075]: python threads support enabled                           
example.com uwsgi[71075]: your mercy for graceful operations on workers is 60 seconds
example.com uwsgi[71075]: *** Operational MODE: no-workers ***                     
example.com uwsgi[71075]: spawned uWSGI master process (pid: 71075)       
example.com systemd[1]: Started Example uWSGI Emperor
example.com uwsgi[71075]: spawned uWSGI fastrouter 1 (pid: 71077)       
example.com uwsgi[71076]: *** starting uWSGI Emperor ***                           
example.com uwsgi[71078]: unknown option --include       
example.com uwsgi[71080]: unknown option --include                                 
example.com uwsgi[71080]: usage: /usr/bin/python3.10 [option] ... [-c cmd | -m mod | file | -] [arg] ... 
example.com uwsgi[71080]: Try `python -h' for more information. -

I've not yet identified why I've started seeing unknown option --include but ignoring that as a side issue in the meantime.

Thanks to all those that have already looked at this already

Lalufu commented 9 months ago

I believe the pyuwsgi issue has been resolved, there's a 2.0.23.post0 release that should not have this issue.

scastlara commented 9 months ago

I believe the pyuwsgi issue has been resolved, there's a 2.0.23.post0 release that should not have this issue.

That is still not published on PyPi, no (https://pypi.org/project/pyuwsgi/#history) ? Are there any plans to do so?

Lalufu commented 9 months ago

That would be a question for @ipmb and the https://github.com/lincolnloop/pyuwsgi-wheels/ project.

ipmb commented 9 months ago

I want to avoid pushing another potentially bad version to PyPI. I believe the issue is resolved, but have not gotten confirmation from anyone that the wheels I linked to here are actually working. If I could get a second set of eyes on them, I will publish them asap.

https://github.com/unbit/uwsgi/issues/2579#issuecomment-1854855038

onegreyonewhite commented 9 months ago

I want to avoid pushing another potentially bad version to PyPI. I believe the issue is resolved, but have not gotten confirmation from anyone that the wheels I linked to here are actually working. If I could get a second set of eyes on them, I will publish them asap.

#2579 (comment)

@ipmb thank u for the good work 👍🏼 I checked it on my laptop and everything works as expected.

[uWSGI] getting INI configuration from /home/grey/Projects/vst-utils/vstutils/web.ini
Keep-Alive mode enabled
uWSGI metrics enabled
Run quick with lib `quick`
*** Starting uWSGI 2.0.23 (64bit) on [Tue Jan  9 22:48:07 2024] ***
compiled with version: 10.2.1 20210130 (Red Hat 10.2.1-11) on 13 December 2023 22:08:06
os: Linux-6.5.0-10013-tuxedo #16 SMP PREEMPT_DYNAMIC Mon Dec 18 11:55:02 UTC 2023
nodename: grey-notebook
machine: x86_64
clock source: unix
pcre jit disabled
detected number of CPU cores: 12
current working directory: /home/grey/Projects/vst/quick
writing pidfile to /tmp/quick_web.pid
detected binary path: /home/grey/.pyenv/versions/3.12.1/bin/python3.12
your processes number limit is 255561
your memory page size is 4096 bytes
detected max file descriptor number: 1024
building mime-types dictionary from file /etc/mime.types...1517 entry found
building mime-types dictionary from file /etc/mime.types...1517 entry found
lock engine: pthread robust mutexes
thunder lock: disabled (you can enable it with --thunder-lock)
uwsgi socket 0 bound to TCP address :8080 fd 3
uwsgi socket 1 bound to TCP address :8081 fd 4
Python version: 3.12.1 (main, Dec 20 2023, 15:39:09) [GCC 11.4.0]
--- Python VM already initialized ---
*** Python threads support is disabled. You can enable it with --enable-threads ***
Python main interpreter initialized at 0x7f3a3e8c3708
your server socket listen backlog is limited to 128 connections
your mercy for graceful operations on workers is 60 seconds
mapped 145808 bytes (142 KB) for 1 cores
*** Operational MODE: single process ***
initialized 39 metrics
*** no app loaded. going in full dynamic mode ***
*** uWSGI is running in multiple interpreter mode ***
spawned uWSGI master process (pid: 46320)
spawned uWSGI worker 1 (pid: 46321, cores: 1)
metrics collector thread started
[uwsgi-daemons] spawning "celery --app=quick.wapp:app worker   --loglevel=WARNING --pidfile=/tmp/quick_worker.pid --autoscale=4,1 --hostname=grey@%h --beat --logfile=/dev/null --queues=celery" (uid: 1000 gid: 1000)
start uvicorn worker 1
INFO:     Started server process [46321]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
Stale pidfile exists - Removing it.

But I use custom worker. Simple check uwsgi --http :8080 --module quick.wsgi also works without errors.

ipmb commented 9 months ago

pyuwsgi 2.0.23.post0 is on PyPI now https://pypi.org/project/pyuwsgi/2.0.23.post0/

scastlara commented 9 months ago

I can confirm it works on my side. Thanks @ipmb 🙏🏽 🙏🏽

unbit / uwsgi