transaction errors in postgres

[wichert@…]

​Plone migrated yesterday from its previous horrible tracker system to trac. The new system is running trac 0.9.1 (from svn) under mod_python with a postgres database.

We get a lot of errors like this:

Oops...

Trac detected an internal error:

ERROR:  current transaction is aborted, commands ignored until end of
transaction block

SELECT username,action FROM permission
Traceback (most recent call last):
  File "/usr/lib/python2.3/site-packages/trac/web/modpython_frontend.py", line
206, in handler
    dispatch_request(mpr.path_info, mpr, env)
  File "/usr/lib/python2.3/site-packages/trac/web/main.py", line 139, in
dispatch_request
    dispatcher.dispatch(req)
  File "/usr/lib/python2.3/site-packages/trac/web/main.py", line 80, in
dispatch
    req.perm = PermissionCache(self.env, req.authname)
  File "/usr/lib/python2.3/site-packages/trac/perm.py", line 276, in __init__
    self.perms = PermissionSystem(env).get_user_permissions(username)
  File "/usr/lib/python2.3/site-packages/trac/perm.py", line 132, in
get_user_permissions
    for perm in self.store.get_user_permissions(username):
  File "/usr/lib/python2.3/site-packages/trac/perm.py", line 213, in
get_user_permissions
    cursor.execute("SELECT username,action FROM permission")
ProgrammingError: ERROR:  current transaction is aborted, commands ignored until
end of transaction block

SELECT username,action FROM permission

reloading the page generally seems to help, but the chances of getting this error seem to be pretty high.

I suspect this can be caused by not closing a transaction after a failed query, which leads to this error if a new requests reuses the connection from the connection pool.

[Christian Boos]

While waiting for the resolution of this problem, you should use PySqlite, as it is (now) more robust in this situation.

#2170 was also related to the above problem, I believe. The code related to session management should be cleaned-up.

For example, I still get this kind of error, but with pysqlite it's only visible in the log, not for the user:

Trac[svn_fs] DEBUG: Opening subversion file-system at /volume/srv/svn/bct_reposi
tory with scope /
Trac[session] INFO: Refreshing session 4bbf5e62ffddfb189934ce1c
Trac[session] DEBUG: Adding variable diff_style with value "sidebyside" to sessi
on 4bbf5e62ffddfb189934ce1c
Trac[session] DEBUG: Adding variable last_visit with value "1133431409" to sessi
on 4bbf5e62ffddfb189934ce1c
Trac[session] DEBUG: Purging old, expired, sessions.
dserver.bct.de - - [01/Dec/2005 11:03:30] "POST /stable-bct-trac/changeset/7290
HTTP/1.1" 302 -
Trac[session] DEBUG: Adding variable diff_style with value "sidebyside" to sessi
on 4bbf5e62ffddfb189934ce1c
Trac[svn_fs] DEBUG: Closing subversion file-system at /volume/srv/svn/bct_reposi
tory
Trac[main] ERROR: columns sid, var_name are not unique
Traceback (most recent call last):
  File "/opt/trac/stable-bct-trac/lib/python2.3/site-packages/trac/web/standalon
e.py", line 235, in _do_trac_req
    dispatch_request(path_info, req, env)
  File "/opt/trac/stable-bct-trac/lib/python2.3/site-packages/trac/web/main.py",
 line 139, in dispatch_request
    dispatcher.dispatch(req)
  File "/opt/trac/stable-bct-trac/lib/python2.3/site-packages/trac/web/main.py",
 line 116, in dispatch
    req.session.save()
  File "/opt/trac/stable-bct-trac/lib/python2.3/site-packages/trac/web/session.p
y", line 157, in save
    (self.sid, authenticated, k, v))
  File "/opt/trac/stable-bct-trac/lib/python2.3/site-packages/trac/db.py", line
216, in execute
    raise e
OperationalError: columns sid, var_name are not unique

[Jonas Borgström]

Are you sure you're running Trac 0.9.1? I can reproduce this with trac trunk but not with 0.9.1.