copr Frontend failure - err 500 - weird datetime errors

[Sun Feb 09 10:57:39.626598 2025] [wsgi:error] [pid 3778094:tid 3778101] [remote 82.60.144.220:54516] ImportError: datetime initialization failed
[Sun Feb 09 10:57:40.395820 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158] mod_wsgi (pid=3775144): Failed to exec Python script file '/usr/share/copr/coprs_frontend/application'.
[Sun Feb 09 10:57:40.395910 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158] mod_wsgi (pid=3775144): Exception occurred processing WSGI script '/usr/share/copr/coprs_frontend/application'.
[Sun Feb 09 10:57:40.396682 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158] Traceback (most recent call last):
[Sun Feb 09 10:57:40.398225 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]   File "/usr/share/copr/coprs_frontend/application", line 11, in <module>
[Sun Feb 09 10:57:40.398247 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     from coprs import app
[Sun Feb 09 10:57:40.398263 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]   File "/usr/share/copr/coprs_frontend/coprs/__init__.py", line 45, in <module>
[Sun Feb 09 10:57:40.398273 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     db = SQLAlchemy(app, engine_options={"future": True})
[Sun Feb 09 10:57:40.398287 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]   File "/usr/lib/python3.13/site-packages/flask_sqlalchemy/extension.py", line 221, in __init__
[Sun Feb 09 10:57:40.398297 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     self.init_app(app)
[Sun Feb 09 10:57:40.398305 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     ~~~~~~~~~~~~~^^^^^
[Sun Feb 09 10:57:40.398318 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]   File "/usr/lib/python3.13/site-packages/flask_sqlalchemy/extension.py", line 329, in init_app
[Sun Feb 09 10:57:40.398328 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     engines[key] = self._make_engine(key, options, app)
[Sun Feb 09 10:57:40.398336 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]                    ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^
[Sun Feb 09 10:57:40.398350 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]   File "/usr/lib/python3.13/site-packages/flask_sqlalchemy/extension.py", line 617, in _make_engine
[Sun Feb 09 10:57:40.398359 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     return sa.engine_from_config(options, prefix="")
[Sun Feb 09 10:57:40.398367 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]            ~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^
[Sun Feb 09 10:57:40.398415 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]   File "/usr/lib64/python3.13/site-packages/sqlalchemy/engine/create.py", line 820, in engine_from_config
[Sun Feb 09 10:57:40.398427 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     return create_engine(url, **options)
[Sun Feb 09 10:57:40.398441 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]   File "<string>", line 2, in create_engine
[Sun Feb 09 10:57:40.398454 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]   File "/usr/lib64/python3.13/site-packages/sqlalchemy/util/deprecations.py", line 281, in warned
[Sun Feb 09 10:57:40.398463 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     return fn(*args, **kwargs)  # type: ignore[no-any-return]
[Sun Feb 09 10:57:40.398475 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]   File "/usr/lib64/python3.13/site-packages/sqlalchemy/engine/create.py", line 599, in create_engine
[Sun Feb 09 10:57:40.398484 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     dbapi = dbapi_meth(**dbapi_args)
[Sun Feb 09 10:57:40.398497 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]   File "/usr/lib64/python3.13/site-packages/sqlalchemy/dialects/postgresql/psycopg2.py", line 690, in import_dbapi
[Sun Feb 09 10:57:40.398523 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     import psycopg2
[Sun Feb 09 10:57:40.398538 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]   File "/usr/lib64/python3.13/site-packages/psycopg2/__init__.py", line 51, in <module>
[Sun Feb 09 10:57:40.398547 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     from psycopg2._psycopg import (                     # noqa
[Sun Feb 09 10:57:40.398556 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     ...<10 lines>...
[Sun Feb 09 10:57:40.398564 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158]     )
[Sun Feb 09 10:57:40.398586 2025] [wsgi:error] [pid 3775144:tid 3775160] [remote 178.20.201.228:56158] ImportError: datetime initialization failed

We've been offline for several hours.

Feb 09 '25 11:02 praiskup

similar issue - https://github.com/psycopg/psycopg2/issues/404

Feb 12 '25 12:02 nikromen

From dnf5.log

2025-02-09T06:18:44+0000 [3763355] DEBUG [librepo] lr_download: Target: Packages/p/python3-3.13.2-1.fc41.x86_64.rpm (-)
2025-02-09T06:18:44+0000 [3763355] DEBUG [librepo] lr_download: Target: Packages/p/python3-libs-3.13.2-1.fc41.x86_64.rpm (-) 
2025-02-09T06:18:44+0000 [3763355] DEBUG [librepo] Selecting mirror for: Packages/p/python-unversioned-command-3.13.2-1.fc41.noarch.rpm

Feb 12 '25 12:02 praiskup

Seems like a security update during weekend, which used to be "fixed" with DNF4. After moving to F41 we likely update during week-days.

Feb 12 '25 12:02 praiskup

I am going to dump relevant information from conversations we had during the week:

The original issue with failing to import datetime is not relevant. It was caused by DNF automatic upgrading python3-libs and not restarting httpd afterward. We had similar issues in the past, see #3327
The important thing is that this happened on Sunday and shouldn't have because we have https://pagure.io/fedora-infra/ansible/pull-request/2228
The fix cannot be done in /usr/lib/systemd/system/dnf-automatic.timer because it gets replaced when updating dnf5-plugin-automatic. It needs to be done as a drop-in. (I am working on this)
We would like to use Tracer hooks to automatically restart httpd when needed but we need to implement DNF5 tracer plugin first (there is only one for DNF4)

Feb 13 '25 14:02 FrostyX

It needs to be done as a drop-in. (I am working on this)

PR: https://pagure.io/fedora-infra/ansible/pull-request/2469

Feb 13 '25 15:02 FrostyX

Related to the auto restarting, see https://pagure.io/fedora-infrastructure/issue/12397 (using libdnf5 actions plugin to do restart on upgrade of some specific packages)

Feb 13 '25 18:02 nirik

We think that this is going to be handled by Fedora Infra base role; we expect httpd restarts to be done automatically without our own intervention, @FrostyX is going to check this is right and then close.

Feb 24 '25 12:02 praiskup

We think that this is going to be handled by Fedora Infra base role; we expect httpd restarts to be done automatically without our own intervention, @FrostyX is going to check this is right and then close.

I was half-correct. It is indeed handled by Fedora Infra role https://pagure.io/fedora-infra/ansible/blob/main/f/roles/mod_wsgi and it should do exactly what we want.

However, we don't use the role. I enabled it on STG to see if it breaks anything https://pagure.io/fedora-infra/ansible/blob/main/f/roles/copr/frontend/tasks/main.yml#_146-150

Feb 26 '25 10:02 FrostyX

I tried running beaker tests against the STG instance and everything seems fine. Just finished deploying this to production.

Feb 27 '25 10:02 FrostyX