gitea git commit hooks failing to trac upgrade of trac.db.api.DatabaseManager

[lr@…]

Since our upgrade to Trac 1.6, we've been having this issue with our git commit hooks giving error

Error: Unable to check for upgrade of trac.db.api.DatabaseManager: TimeoutError: Unable to get database connection within 0 seconds.

As documented here:

​https://trac.osgeo.org/osgeo/ticket/3286

Our commit hooks are doing nothing but something like:

trac-admin /var/www/trac/env/postgis/ changeset added git bdecd88fe3f506b2b1f64de3f6cf25dc8f102f66

under our git user account.

We've manually tried these commands under our git account and they succeed whenever we do them, just not working under our git commit hooks.

We are at a loss to troubleshoot this, as there doesn't seem to be any log entry in the postgresql logs about this.

attached is a sample of one of our git hooks which is run under the post-receive git hook.

[lr@…]

git hook

[Jun Omae]

Please share trac.log in your Trac environment. The traceback of the error might be loggged.

Also, trac-admin command should be invoked with the same user of Trac web process, instead of git user (e.g. www-data user in the case of apache with mod-wsgi).

[anonymous]

Replying to Jun Omae:

Please share trac.log in your Trac environment. The traceback of the error might be loggged.

Also, trac-admin command should be invoked with the same user of Trac web process, instead of git user (e.g. www-data user in the case of apache with mod-wsgi).

I have to review how our gitea app is set up cause that runs under the git user and is the one triggering the git web hook.

Here is what the trac log shows when it fails.

TypeError: sequence item 3: expected str instance, NoneType found
[2024-10-09 17:25:03,202] postgis:env WARNING: Component <Component trac.db.api.DatabaseManager> failed with TimeoutError: Unable to get database connection within 0 seconds.

[anonymous]

Forgot to mention our backend database is postgresql 16 if that matters.

I tried the commands both under git account and www-data and they both work

e.g.

sudo -u git trac-admin /var/www/trac/env/postgis/ changeset added git 77eddb114e21ec0b7eba2b5caa496d7e864ef247

or

sudo -u www-data trac-admin /var/www/trac/env/postgis/ changeset added git 77eddb114e21ec0b7eba2b5caa496d7e864ef247

[Jun Omae]

Replying to anonymous:

Replying to Jun Omae:

Please share trac.log in your Trac environment. The traceback of the error might be loggged.

Also, trac-admin command should be invoked with the same user of Trac web process, instead of git user (e.g. www-data user in the case of apache with mod-wsgi).

I have to review how our gitea app is set up cause that runs under the git user and is the one triggering the git web hook.

I'd suggest to be the same user to use for trac-admin via gitea and mod-wsgi processes, in order to prevent several troubles. Because Trac environment, especially trac.log, will be written from both processes. The user of mod-wsgi could be changed using ​WSGIDaemonProcess user parameter, if the user of gitea cannot be changed.

Here is what the trac log shows when it fails.

TypeError: sequence item 3: expected str instance, NoneType found
[2024-10-09 17:25:03,202] postgis:env WARNING: Component <Component trac.db.api.DatabaseManager> failed with TimeoutError: Unable to get database connection within 0 seconds.

Thanks. However, it is hard to investigate it cause of no traceback….

[Jun Omae]

I consider that PostgreSQLConnection or psycopg2 module raises the TypeError due to something wrong when trac-admin is invoked from post-commit hook. Also, Trac doesn't unfortunately log when the exception is raised.

Please try to enable [trac] debug_sql option to log the exception, and report the log if the same is encountered.

We should log the exception when failure to connect the database, regardless of the option.

trac/db/api.py

@@ -417 +417 @@
         if not self._cnx_pool:
             connector, args = self.get_connector()
             self._cnx_pool = ConnectionPool(5, connector, **args)
-        db = self._cnx_pool.get_cnx(self.timeout or None)
+        db = self._cnx_pool.get_cnx(self.timeout or None, self.log)
         if readonly:
             db = ConnectionWrapper(db, readonly=True)
         return db

trac/db/pool.py

@@ -65 +65 @@
         self._pool_time = []
         self._waiters = 0
 
-    def get_cnx(self, connector, kwargs, timeout=None):
+    def get_cnx(self, connector, kwargs, timeout=None, log=None):
         cnx = None
-        log = kwargs.get('log')
         key = str(kwargs)
         start = time_now()
         tid = get_thread_id()
@@ -210 +209 @@
         self._connector = connector
         self._kwargs = kwargs
 
-    def get_cnx(self, timeout=None):
-        return _backend.get_cnx(self._connector, self._kwargs, timeout)
+    def get_cnx(self, timeout=None, log=None):
+        return _backend.get_cnx(self._connector, self._kwargs, timeout, log)
 
     def shutdown(self, tid=None):
         _backend.shutdown(tid)

[anonymous]

Thanks for all the help that helped a lot.

Now we are seeing:

psycopg2.OperationalError: connection to server on socket "/var/run/postgresql/.s.PGSQL.5432" failed: fe_sendauth: no password supplied

So I think that answers the question. Got to check why it's not getting the password in the config I guess when it does with direct tracadmin calls.

[anonymous]

Okay I'm still a bit puzzled. If I set postgresql to trust mode for local connections it works as expected so that does seem to be the culprit.

I checked both the git account and the www-data account and both do have .pgpass with the user name trac and password used to connect to all our trac databases, and I confirmed logging in as git or www-data, I can connect to the databases via psql not providing a password. It also doesn't explain why calling tracadmin direct from either of those accounts works fine.

Here is the full trace:

[2024-10-10 08:20:42,523] postgis:env ERROR: Exception caught while checking for upgrade: TracError: Unable to check for upgrade of trac.db.api.DatabaseManager: TimeoutError: Unable to get database connection within 0 seconds.
[2024-10-10 08:20:43,151] postgis:pool ERROR: Exception caught on ping
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/dist-packages/trac/db/pool.py", line 99, in get_cnx
    cnx.ping()
  File "/usr/local/lib/python3.11/dist-packages/trac/db/postgres_backend.py", line 407, in ping
    cursor.execute('SELECT 1')
psycopg2.OperationalError: server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.

[2024-10-10 08:22:08,794] postgis:pool ERROR: Exception caught on ping
Traceback (most recent call last):
  File "/usr/local/lib/python3.11/dist-packages/trac/db/pool.py", line 99, in get_cnx
    cnx.ping()
  File "/usr/local/lib/python3.11/dist-packages/trac/db/postgres_backend.py", line 407, in ping
    cursor.execute('SELECT 1')
psycopg2.OperationalError: server closed the connection unexpectedly
        This probably means the server terminated abnormally
        before or while processing the request.

[2024-10-10 08:26:19,219] postgis:pool ERROR: Exception caught on create
Traceback (most recent call last):
  File "/usr/lib/python3.11/cmd.py", line 214, in onecmd
    func = getattr(self, 'do_' + cmd)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^
AttributeError: 'TracAdmin' object has no attribute 'do_changeset'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.11/dist-packages/trac/db/pool.py", line 103, in get_cnx
    cnx = connector.get_connection(**kwargs)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/trac/db/postgres_backend.py", line 150, in get_connection
    cnx = PostgreSQLConnection(path, log, user, password, host, port,
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/dist-packages/trac/db/postgres_backend.py", line 330, in __init__
    cnx = psycopg.connect(assemble_pg_dsn(path, user, password, host,
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/psycopg2/__init__.py", line 122, in connect
    conn = _connect(dsn, connection_factory=connection_factory, **kwasync)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
psycopg2.OperationalError: connection to server on socket "/var/run/postgresql/.s.PGSQL.5432" failed: fe_sendauth: no password supplied

[Jun Omae]

Thanks for the feedback. The root cause is on configurations of pg_hba.conf and [trac] database. I'd suggest asking on PostgreSQL users mailing list or forum about the authentication settings with socket.

I think that TypeError: sequence item 3: expected str instance, NoneType found is probably logged by another issue.

[Jun Omae]

Replying to Jun Omae:

Thanks for the feedback. The root cause is on configurations of pg_hba.conf and [trac] database. I'd suggest asking on PostgreSQL users mailing list or forum about the authentication settings with socket.

In addition, check postgresql log for the authentication and authorization issues.

[lr@…]

Replying to Jun Omae:

Replying to Jun Omae:

Thanks for the feedback. The root cause is on configurations of pg_hba.conf and [trac] database. I'd suggest asking on PostgreSQL users mailing list or forum about the authentication settings with socket.

In addition, check postgresql log for the authentication and authorization issues.

Thanks for all the help. We finally figured out the issue, after checking what environment variables gitea was using.

The culprit was that gitea overrides the home variable to:

HOME=/home/git/gitea/data/home

So it was expecting the PostgreSQL .pgpass file to be there instead of /home/git.

Copying the .pgpass file there fixed the issue.