occasional database error
Greg Troxel
Occasionally ticket queries fail with a database error:
Oops#
Trac detected an internal error:
OperationalError: ERROR: duplicate key violates unique constraint "session_attribute_pk"
The query is this, with host and project name redacted:
and in the log
2008-10-31 06:58:38,521 Trac[main] ERROR: ERROR: duplicate key violates unique constraint "session_attribute_pk"
Traceback (most recent call last):
File "usr/pkg/lib/python2.4/site-packages/trac/web/main.py", line 423, in _dispatch_request
dispatcher.dispatch(req)
File "usr/pkg/lib/python2.4/site-packages/trac/web/main.py", line 222, in dispatch
req.session.save()
File "usr/pkg/lib/python2.4/site-packages/trac/web/session.py", line 102, in save
"VALUES(%s,%s,%s,%s)", attrs)
File "usr/pkg/lib/python2.4/site-packages/trac/db/util.py", line 57, in executemany
return self.cursor.executemany(sql_escape_percent(sql), args)
File "usr/pkg/lib/python2.4/site-packages/trac/db/util.py", line 57, in executemany
return self.cursor.executemany(sql_escape_percent(sql), args)
File "/usr/pkg/lib/python2.4/site-packages/pyPgSQL/PgSQL.py", line 3109, in executemany
self.execute(query, _i)
File "/usr/pkg/lib/python2.4/site-packages/pyPgSQL/PgSQL.py", line 3072, in execute
raise OperationalError, msg
OperationalError: ERROR: duplicate key violates unique constraint "session_attribute_pk"
Usually this query works fine - when I get the error I can just reload
(recent firefox 2 over ssl)
I am running 0.11.1 on NetBSD 4 i386 via Xen3 with postresql back end
and the following software versions:
ap22-py24-python-3.3.1 Apache module that embeds the Python interpreter
ap22-py24-wsgi-2.3 WSGI module for apache
ap22-subversion-1.5.4 WebDAV server (Apache module) for Subversion
apache-2.2.9nb5 Apache HTTP (Web) server, version 2
apr-1.3.3 Apache Portable Runtime
apr-util-1.3.4 Apache Portable Runtime utilities
py24-PgSQL-2.4nb5 Python DB-API 2.0 compliant interface to PostgreSQL
py24-babel-0.9.4 Collection of tools for internationalizing Python applications
py24-expat-0nb4 Python interface to expat
py24-genshi-0.5.1 Python toolkit for generation of output for the web
py24-mxDateTime-2.0.6nb1 Python extension that provides types and conversions for dates
py24-pytz-2008bnb1 World timezone definitions, modern and historical
py24-setuptools-0.6c8 New Python packaging system
py24-subversion-1.5.4 Python bindings and tools for Subversion
python24-2.4.5nb2 Interpreted, interactive, object-oriented programming language
subversion-base-1.5.4 Version control system, base programs and libraries
trac-0.11.1nb3 Subversion repository browser, wiki, and issue tracking system
Jonas Borgström
> Occasionally ticket queries fail with a database error:
>
> Oops#
> Trac detected an internal error:
>
> OperationalError: ERROR: duplicate key violates unique constraint "session_attribute_pk"
Hi Greg,
It appears to be a small window of opportunity for two concurrent
requests from a single user to cause this constraint violation in
session.py.
I have attached a patch which I think will fix this which I'm currently
testing. If you have the opportunity please give it a try as well.
/ Jonas
Greg Troxel
Greg Troxel wrote:
> Occasionally ticket queries fail with a database error:
>
> Oops#
> Trac detected an internal error:
>
> OperationalError: ERROR: duplicate key violates unique constraint "session_attribute_pk"
It appears to be a small window of opportunity for two concurrent
requests from a single user to cause this constraint violation in
session.py.
I have attached a patch which I think will fix this which I'm currently
testing. If you have the opportunity please give it a try as well.
Thanks; I have installed the patch.
I don't quite understand what is going on. I think the error happened
on the INSERT, but on reflection this is because of two similar
transactions:
delete foo if foo is there
insert bar
and the point is that the delete doesn't fail. Your patch is to try to
catch the delete failing, and skip the insert. But I would expect the
delete to return DELETE 0, which doesn't seem like an error:
trac-redacted2=# delete from session_attribute where sid = 'no-such-user';
DELETE 0
Is this because we are running read committed instead of full
transactions? We are having the second transaction to do the insert see
database state from before the first insert is committed.
Jonas Borgström
> I don't quite understand what is going on. I think the error happened
> on the INSERT, but on reflection this is because of two similar
> transactions:
>
> delete foo if foo is there
> insert bar
>
> and the point is that the delete doesn't fail. Your patch is to try to
> catch the delete failing, and skip the insert. But I would expect the
> delete to return DELETE 0, which doesn't seem like an error:
>
> trac-redacted2=# delete from session_attribute where sid = 'no-such-user';
> DELETE 0
>
> Is this because we are running read committed instead of full
> transactions? We are having the second transaction to do the insert see
> database state from before the first insert is committed.
Yes you're right. It's the INSERT statement and not the DELETE statement
that might fail if another transaction manages to execute and commit
between the DELETE and INSERT of the first transaction (if read
committed is being used).
I somehow managed to wrap the wrong cursor.execute statement with an
exception handler.
I've attached an updated version of the patch.
Thanks for spotting this!
/ Jonas
Christian Boos
I also wondered a bit about that DELETE... thought there was something
special going on ;-)
So, I think it's just another symptom of #3563, and we can track this
defect in http://trac.edgewall.org/ticket/7663.
Another last minute candidate for 0.11.2 in case everything works fine
with the patch?
-- Christian
Greg Troxel
Yes you're right. It's the INSERT statement and not the DELETE statement
that might fail if another transaction manages to execute and commit
between the DELETE and INSERT of the first transaction (if read
committed is being used).
I somehow managed to wrap the wrong cursor.execute statement with an
exception handler.
I've attached an updated version of the patch.
Thanks, will apply and rebuild.
Should we be thinking about setting backends to use full transactions
instead of READ COMMITTED, as in
set transaction ISOLATION LEVEL SERIALIZABLE ;
perhaps only for such operations, but maybe for more?
(I have no idea if this works in sqlite, and it seems even in PostgreSQL
one can get phantom reads with SERIALIZABLE.)
Jonas Borgström
> I also wondered a bit about that DELETE... thought there was something
> special going on ;-)
Heh not really, just sloppiness on my part ;) I didn't even realize the
patch was fubared until I read Greg's response.
> So, I think it's just another symptom of #3563, and we can track this
> defect in http://trac.edgewall.org/ticket/7663.
> Another last minute candidate for 0.11.2 in case everything works fine
> with the patch?
Probably, I'm currently testing it on t.e.o which before this patch did
hit this issue about once or twice a day.
/ Jonas
Jonas Borgström
> Thanks, will apply and rebuild.
>
> Should we be thinking about setting backends to use full transactions
> instead of READ COMMITTED, as in
>
> set transaction ISOLATION LEVEL SERIALIZABLE ;
>
> perhaps only for such operations, but maybe for more?
Not unless we really have to since that will bring the PostgreSQL
concurrency level down to something close to sqlite.
If this really happens frequent enough to be an issue (which I don't
think it is) we should instead rewrite the session code to be smarter
about updating session attributes.
Instead of deleting all attributes and inserting them again as soon as
some attribute is updated we should try to update only actually modified
attributes.
This would reduce the risk of causing a conflict.
/ Jonas