Possible transaction bug with isolation level serialisable? - Mailing list pgsql-bugs

Hi,

Two concurrent transaction first check if a certain value is listed in a =
table and if not try to insert it. As the value inserted hasto be unique =
and both try to enter the same one, one transaction fails reporting that =
the value is already part of the table. As both are executed within a =
transaction with isolation level SERIALIZABLE I would have expected that =
one of them would return with a serialization failure, which my program =
would have been ready to handle and re-execute the transaction.

The reason I think something is fishy is, because I find the behaviour =
is somehow similar to a nonrepeatable read which should not occur with =
this transaction level. The=20

SELECT "userRef" FROM "VerifyQueue" WHERE lower("email")=3Dlower($1)

reports, that the value is NOT in the table, thus the program then tries =
to insert it, and at that point the value is shown as being in the =
table.

So is this a bug, or did I misunderstand something?

This is with version 9.3.4 of PostgreSQL.

$ psql --version; postgres --version; uname -a
psql (PostgreSQL) 9.3.4
postgres (PostgreSQL) 9.3.4
Darwin Claudios-MacBook-Pro.local 13.1.0 Darwin Kernel Version 13.1.0: =
Wed Apr  2 23:52:02 PDT 2014; root:xnu-2422.92.1~2/RELEASE_X86_64 x86_64

Here all the lines from the log file concerning the two transactions.=20

2014-04-23 23:58:48 CEST [63576]: [1-1] user=3D[unknown],db=3D[unknown] =
LOG:  connection received: host=3D127.0.0.1 port=3D62251
2014-04-23 23:58:48 CEST [63584]: [1-1] user=3D[unknown],db=3D[unknown] =
LOG:  connection received: host=3D127.0.0.1 port=3D62259
2014-04-23 23:58:48 CEST [63584]: [2-1] user=3Dreslist,db=3Dreslist LOG: =
 connection authorized: user=3Dreslist database=3Dreslist
2014-04-23 23:58:48 CEST [63584]: [3-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.210 ms  parse <unnamed>: SET extra_float_digits =3D 3
2014-04-23 23:58:48 CEST [63584]: [4-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.021 ms  bind <unnamed>: SET extra_float_digits =3D 3
2014-04-23 23:58:48 CEST [63584]: [5-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.012 ms  execute <unnamed>: SET extra_float_digits =3D 3
2014-04-23 23:58:48 CEST [63576]: [2-1] user=3Dreslist,db=3Dreslist LOG: =
 connection authorized: user=3Dreslist database=3Dreslist
2014-04-23 23:58:48 CEST [63584]: [6-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.051 ms  parse <unnamed>: SET SESSION CHARACTERISTICS AS =
TRANSACTION ISOLATION LEVEL SERIALIZABLE
2014-04-23 23:58:48 CEST [63584]: [7-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.007 ms  bind <unnamed>: SET SESSION CHARACTERISTICS AS =
TRANSACTION ISOLATION LEVEL SERIALIZABLE
2014-04-23 23:58:48 CEST [63584]: [8-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.009 ms  execute <unnamed>: SET SESSION CHARACTERISTICS AS =
TRANSACTION ISOLATION LEVEL SERIALIZABLE
2014-04-23 23:58:48 CEST [63584]: [9-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.025 ms  parse <unnamed>: BEGIN
2014-04-23 23:58:48 CEST [63584]: [10-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.005 ms  bind <unnamed>: BEGIN
2014-04-23 23:58:48 CEST [63584]: [11-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.006 ms  execute <unnamed>: BEGIN
2014-04-23 23:58:48 CEST [63584]: [12-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 1.370 ms  parse <unnamed>: SELECT "id" FROM "User" WHERE =
"nick"=3D$1 AND "deleted" IS NULL
2014-04-23 23:58:48 CEST [63576]: [3-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.224 ms  parse <unnamed>: SET extra_float_digits =3D 3
2014-04-23 23:58:48 CEST [63576]: [4-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.024 ms  bind <unnamed>: SET extra_float_digits =3D 3
2014-04-23 23:58:48 CEST [63576]: [5-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.015 ms  execute <unnamed>: SET extra_float_digits =3D 3
2014-04-23 23:58:48 CEST [63576]: [6-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.037 ms  parse <unnamed>: SET SESSION CHARACTERISTICS AS =
TRANSACTION ISOLATION LEVEL SERIALIZABLE
2014-04-23 23:58:48 CEST [63576]: [7-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.006 ms  bind <unnamed>: SET SESSION CHARACTERISTICS AS =
TRANSACTION ISOLATION LEVEL SERIALIZABLE
2014-04-23 23:58:48 CEST [63576]: [8-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.009 ms  execute <unnamed>: SET SESSION CHARACTERISTICS AS =
TRANSACTION ISOLATION LEVEL SERIALIZABLE
2014-04-23 23:58:48 CEST [63584]: [13-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.684 ms  bind <unnamed>: SELECT "id" FROM "User" WHERE =
"nick"=3D$1 AND "deleted" IS NULL
2014-04-23 23:58:48 CEST [63584]: [14-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen'
2014-04-23 23:58:48 CEST [63584]: [15-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.024 ms  execute <unnamed>: SELECT "id" FROM "User" =
WHERE "nick"=3D$1 AND "deleted" IS NULL
2014-04-23 23:58:48 CEST [63584]: [16-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen'
2014-04-23 23:58:48 CEST [63576]: [9-1] user=3Dreslist,db=3Dreslist LOG: =
 duration: 0.026 ms  parse <unnamed>: BEGIN
2014-04-23 23:58:48 CEST [63576]: [10-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.005 ms  bind <unnamed>: BEGIN
2014-04-23 23:58:48 CEST [63576]: [11-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.007 ms  execute <unnamed>: BEGIN
2014-04-23 23:58:48 CEST [63584]: [17-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.227 ms  parse <unnamed>: SELECT "userRef" FROM =
"VerifyQueue" WHERE lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63584]: [18-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.265 ms  bind <unnamed>: SELECT "userRef" FROM =
"VerifyQueue" WHERE lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63584]: [19-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen@gmail.com'
2014-04-23 23:58:48 CEST [63584]: [20-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.014 ms  execute <unnamed>: SELECT "userRef" FROM =
"VerifyQueue" WHERE lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63584]: [21-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen@gmail.com'
2014-04-23 23:58:48 CEST [63584]: [22-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.258 ms  parse <unnamed>: SELECT =
"User"."id","User"."nick","User"."address","User"."givenname","User"."surn=
ame","User"."email","User"."newmailNotification","User"."realnameVisible",=
"User"."language","User"."last_login","User"."creationTime","User"."delete=
d","Host"."name","Service"."name","User"."password","User"."salt" FROM =
"User" INNER JOIN "Host" ON "User"."hostRef"=3D"Host"."id" INNER JOIN =
"Service" ON "Host"."serviceRef"=3D"Service"."id" WHERE =
lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63576]: [12-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 1.241 ms  parse <unnamed>: SELECT "id" FROM "User" WHERE =
"nick"=3D$1 AND "deleted" IS NULL
2014-04-23 23:58:48 CEST [63584]: [23-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.434 ms  bind <unnamed>: SELECT =
"User"."id","User"."nick","User"."address","User"."givenname","User"."surn=
ame","User"."email","User"."newmailNotification","User"."realnameVisible",=
"User"."language","User"."last_login","User"."creationTime","User"."delete=
d","Host"."name","Service"."name","User"."password","User"."salt" FROM =
"User" INNER JOIN "Host" ON "User"."hostRef"=3D"Host"."id" INNER JOIN =
"Service" ON "Host"."serviceRef"=3D"Service"."id" WHERE =
lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63584]: [24-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen@gmail.com'
2014-04-23 23:58:48 CEST [63584]: [25-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.015 ms  execute <unnamed>: SELECT =
"User"."id","User"."nick","User"."address","User"."givenname","User"."surn=
ame","User"."email","User"."newmailNotification","User"."realnameVisible",=
"User"."language","User"."last_login","User"."creationTime","User"."delete=
d","Host"."name","Service"."name","User"."password","User"."salt" FROM =
"User" INNER JOIN "Host" ON "User"."hostRef"=3D"Host"."id" INNER JOIN =
"Service" ON "Host"."serviceRef"=3D"Service"."id" WHERE =
lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63584]: [26-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen@gmail.com'
2014-04-23 23:58:48 CEST [63584]: [27-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.046 ms  parse <unnamed>: SELECT "id" FROM "Host" WHERE =
"name"=3D$1
2014-04-23 23:58:48 CEST [63584]: [28-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.082 ms  bind <unnamed>: SELECT "id" FROM "Host" WHERE =
"name"=3D$1
2014-04-23 23:58:48 CEST [63584]: [29-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'localhost'
2014-04-23 23:58:48 CEST [63584]: [30-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.026 ms  execute <unnamed>: SELECT "id" FROM "Host" =
WHERE "name"=3D$1
2014-04-23 23:58:48 CEST [63584]: [31-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'localhost'
2014-04-23 23:58:48 CEST [63576]: [13-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.639 ms  bind <unnamed>: SELECT "id" FROM "User" WHERE =
"nick"=3D$1 AND "deleted" IS NULL
2014-04-23 23:58:48 CEST [63576]: [14-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen'
2014-04-23 23:58:48 CEST [63576]: [15-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.022 ms  execute <unnamed>: SELECT "id" FROM "User" =
WHERE "nick"=3D$1 AND "deleted" IS NULL
2014-04-23 23:58:48 CEST [63576]: [16-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen'
2014-04-23 23:58:48 CEST [63576]: [17-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.208 ms  parse <unnamed>: SELECT "userRef" FROM =
"VerifyQueue" WHERE lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63576]: [18-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.247 ms  bind <unnamed>: SELECT "userRef" FROM =
"VerifyQueue" WHERE lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63576]: [19-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen@gmail.com'
2014-04-23 23:58:48 CEST [63576]: [20-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.014 ms  execute <unnamed>: SELECT "userRef" FROM =
"VerifyQueue" WHERE lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63576]: [21-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen@gmail.com'
2014-04-23 23:58:48 CEST [63576]: [22-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.345 ms  parse <unnamed>: SELECT =
"User"."id","User"."nick","User"."address","User"."givenname","User"."surn=
ame","User"."email","User"."newmailNotification","User"."realnameVisible",=
"User"."language","User"."last_login","User"."creationTime","User"."delete=
d","Host"."name","Service"."name","User"."password","User"."salt" FROM =
"User" INNER JOIN "Host" ON "User"."hostRef"=3D"Host"."id" INNER JOIN =
"Service" ON "Host"."serviceRef"=3D"Service"."id" WHERE =
lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63576]: [23-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.581 ms  bind <unnamed>: SELECT =
"User"."id","User"."nick","User"."address","User"."givenname","User"."surn=
ame","User"."email","User"."newmailNotification","User"."realnameVisible",=
"User"."language","User"."last_login","User"."creationTime","User"."delete=
d","Host"."name","Service"."name","User"."password","User"."salt" FROM =
"User" INNER JOIN "Host" ON "User"."hostRef"=3D"Host"."id" INNER JOIN =
"Service" ON "Host"."serviceRef"=3D"Service"."id" WHERE =
lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63576]: [24-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen@gmail.com'
2014-04-23 23:58:48 CEST [63576]: [25-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.019 ms  execute <unnamed>: SELECT =
"User"."id","User"."nick","User"."address","User"."givenname","User"."surn=
ame","User"."email","User"."newmailNotification","User"."realnameVisible",=
"User"."language","User"."last_login","User"."creationTime","User"."delete=
d","Host"."name","Service"."name","User"."password","User"."salt" FROM =
"User" INNER JOIN "Host" ON "User"."hostRef"=3D"Host"."id" INNER JOIN =
"Service" ON "Host"."serviceRef"=3D"Service"."id" WHERE =
lower("email")=3Dlower($1)
2014-04-23 23:58:48 CEST [63576]: [26-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen@gmail.com'
2014-04-23 23:58:48 CEST [63576]: [27-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.046 ms  parse <unnamed>: SELECT "id" FROM "Host" WHERE =
"name"=3D$1
2014-04-23 23:58:48 CEST [63576]: [28-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.075 ms  bind <unnamed>: SELECT "id" FROM "Host" WHERE =
"name"=3D$1
2014-04-23 23:58:48 CEST [63576]: [29-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'localhost'
2014-04-23 23:58:48 CEST [63576]: [30-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.021 ms  execute <unnamed>: SELECT "id" FROM "Host" =
WHERE "name"=3D$1
2014-04-23 23:58:48 CEST [63576]: [31-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'localhost'
2014-04-23 23:58:48 CEST [63584]: [32-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.226 ms  parse <unnamed>: INSERT INTO =
"User"("nick","password","salt","address","givenname","surname","email","n=
ewmailNotification","realnameVisible","pictureVisible","language","hostRef=
","creationTime","agb") VALUES =
($1,$2,$3,$4,$5,$6,NULL,$7,$8,$9,$10,$11,$12,$13)
2014-04-23 23:58:48 CEST [63584]: [33-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.136 ms  bind <unnamed>: INSERT INTO =
"User"("nick","password","salt","address","givenname","surname","email","n=
ewmailNotification","realnameVisible","pictureVisible","language","hostRef=
","creationTime","agb") VALUES =
($1,$2,$3,$4,$5,$6,NULL,$7,$8,$9,$10,$11,$12,$13)
2014-04-23 23:58:48 CEST [63584]: [34-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen', $2 =3D =
'HBfkwJDphdr+YDB2Yp7bwC8oci7JSWkOhtn2JFGRcTo=3D', $3 =3D 'ogrUEWQCi/k=3D',=
 $4 =3D 'Technical', $5 =3D 'Testuser', $6 =3D 'Silver', $7 =3D 'f', $8 =
=3D 'f', $9 =3D 'f', $10 =3D 'de', $11 =3D '4', $12 =3D '1398290328', =
$13 =3D '8ZEwvtmABppOjChHuxnGo34EJLgejz/cF4OT+y7W6F8=3D'
2014-04-23 23:58:48 CEST [63576]: [32-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.164 ms  parse <unnamed>: INSERT INTO =
"User"("nick","password","salt","address","givenname","surname","email","n=
ewmailNotification","realnameVisible","pictureVisible","language","hostRef=
","creationTime","agb") VALUES =
($1,$2,$3,$4,$5,$6,NULL,$7,$8,$9,$10,$11,$12,$13)
2014-04-23 23:58:48 CEST [63576]: [33-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.152 ms  bind <unnamed>: INSERT INTO =
"User"("nick","password","salt","address","givenname","surname","email","n=
ewmailNotification","realnameVisible","pictureVisible","language","hostRef=
","creationTime","agb") VALUES =
($1,$2,$3,$4,$5,$6,NULL,$7,$8,$9,$10,$11,$12,$13)
2014-04-23 23:58:48 CEST [63576]: [34-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen', $2 =3D =
'PqhzQDLRd8cNKef2idIhyoNE3/cOPgGomB93PoWhhHM=3D', $3 =3D 'rsJG2GZudz8=3D',=
 $4 =3D 'Technical', $5 =3D 'Testuser', $6 =3D 'Silver', $7 =3D 'f', $8 =
=3D 'f', $9 =3D 'f', $10 =3D 'de', $11 =3D '4', $12 =3D '1398290328', =
$13 =3D '8ZEwvtmABppOjChHuxnGo34EJLgejz/cF4OT+y7W6F8=3D'
2014-04-23 23:58:48 CEST [63584]: [35-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 4.444 ms  execute <unnamed>: INSERT INTO =
"User"("nick","password","salt","address","givenname","surname","email","n=
ewmailNotification","realnameVisible","pictureVisible","language","hostRef=
","creationTime","agb") VALUES =
($1,$2,$3,$4,$5,$6,NULL,$7,$8,$9,$10,$11,$12,$13)
2014-04-23 23:58:48 CEST [63584]: [36-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen', $2 =3D =
'HBfkwJDphdr+YDB2Yp7bwC8oci7JSWkOhtn2JFGRcTo=3D', $3 =3D 'ogrUEWQCi/k=3D',=
 $4 =3D 'Technical', $5 =3D 'Testuser', $6 =3D 'Silver', $7 =3D 'f', $8 =
=3D 'f', $9 =3D 'f', $10 =3D 'de', $11 =3D '4', $12 =3D '1398290328', =
$13 =3D '8ZEwvtmABppOjChHuxnGo34EJLgejz/cF4OT+y7W6F8=3D'
2014-04-23 23:58:48 CEST [63584]: [37-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.096 ms  parse <unnamed>: SELECT currval('"userSeq"')
2014-04-23 23:58:48 CEST [63584]: [38-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.027 ms  bind <unnamed>: SELECT currval('"userSeq"')
2014-04-23 23:58:48 CEST [63584]: [39-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.096 ms  execute <unnamed>: SELECT currval('"userSeq"')
2014-04-23 23:58:48 CEST [63576]: [35-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 4.431 ms  execute <unnamed>: INSERT INTO =
"User"("nick","password","salt","address","givenname","surname","email","n=
ewmailNotification","realnameVisible","pictureVisible","language","hostRef=
","creationTime","agb") VALUES =
($1,$2,$3,$4,$5,$6,NULL,$7,$8,$9,$10,$11,$12,$13)
2014-04-23 23:58:48 CEST [63576]: [36-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen', $2 =3D =
'PqhzQDLRd8cNKef2idIhyoNE3/cOPgGomB93PoWhhHM=3D', $3 =3D 'rsJG2GZudz8=3D',=
 $4 =3D 'Technical', $5 =3D 'Testuser', $6 =3D 'Silver', $7 =3D 'f', $8 =
=3D 'f', $9 =3D 'f', $10 =3D 'de', $11 =3D '4', $12 =3D '1398290328', =
$13 =3D '8ZEwvtmABppOjChHuxnGo34EJLgejz/cF4OT+y7W6F8=3D'
2014-04-23 23:58:48 CEST [63576]: [37-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.080 ms  parse <unnamed>: SELECT currval('"userSeq"')
2014-04-23 23:58:48 CEST [63576]: [38-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.032 ms  bind <unnamed>: SELECT currval('"userSeq"')
2014-04-23 23:58:48 CEST [63576]: [39-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.043 ms  execute <unnamed>: SELECT currval('"userSeq"')
2014-04-23 23:58:48 CEST [63584]: [40-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.112 ms  parse <unnamed>: SELECT "groupRef" FROM =
"InviteQueue" WHERE "token"=3D$1
2014-04-23 23:58:48 CEST [63576]: [40-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.126 ms  parse <unnamed>: SELECT "groupRef" FROM =
"InviteQueue" WHERE "token"=3D$1
2014-04-23 23:58:48 CEST [63584]: [41-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.159 ms  bind <unnamed>: SELECT "groupRef" FROM =
"InviteQueue" WHERE "token"=3D$1
2014-04-23 23:58:48 CEST [63584]: [42-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D NULL
2014-04-23 23:58:48 CEST [63584]: [43-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.003 ms  execute <unnamed>: SELECT "groupRef" FROM =
"InviteQueue" WHERE "token"=3D$1
2014-04-23 23:58:48 CEST [63584]: [44-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D NULL
2014-04-23 23:58:48 CEST [63576]: [41-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.166 ms  bind <unnamed>: SELECT "groupRef" FROM =
"InviteQueue" WHERE "token"=3D$1
2014-04-23 23:58:48 CEST [63576]: [42-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D NULL
2014-04-23 23:58:48 CEST [63576]: [43-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.004 ms  execute <unnamed>: SELECT "groupRef" FROM =
"InviteQueue" WHERE "token"=3D$1
2014-04-23 23:58:48 CEST [63576]: [44-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D NULL
2014-04-23 23:58:48 CEST [63584]: [45-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.041 ms  parse <unnamed>: INSERT INTO =
"VerifyQueue"("email","token","userRef","groupRef","creationTime") =
VALUES ($1,$2,$3,$4,$5)
2014-04-23 23:58:48 CEST [63584]: [46-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.041 ms  bind <unnamed>: INSERT INTO =
"VerifyQueue"("email","token","userRef","groupRef","creationTime") =
VALUES ($1,$2,$3,$4,$5)
2014-04-23 23:58:48 CEST [63584]: [47-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen@gmail.com', $2 =3D =
'fg8t3iG30eTfQyVPb79yhw.html', $3 =3D '1', $4 =3D NULL, $5 =3D =
'1398290328'
2014-04-23 23:58:48 CEST [63576]: [45-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.054 ms  parse <unnamed>: INSERT INTO =
"VerifyQueue"("email","token","userRef","groupRef","creationTime") =
VALUES ($1,$2,$3,$4,$5)
2014-04-23 23:58:48 CEST [63576]: [46-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.100 ms  bind <unnamed>: INSERT INTO =
"VerifyQueue"("email","token","userRef","groupRef","creationTime") =
VALUES ($1,$2,$3,$4,$5)
2014-04-23 23:58:48 CEST [63576]: [47-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen@gmail.com', $2 =3D =
'aF6n8wyzaQ0pBipusp3wg.html', $3 =3D '2', $4 =3D NULL, $5 =3D =
'1398290328'
2014-04-23 23:58:48 CEST [63584]: [48-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 2.576 ms  execute <unnamed>: INSERT INTO =
"VerifyQueue"("email","token","userRef","groupRef","creationTime") =
VALUES ($1,$2,$3,$4,$5)
2014-04-23 23:58:48 CEST [63584]: [49-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D 'silberbatzen@gmail.com', $2 =3D =
'fg8t3iG30eTfQyVPb79yhw.html', $3 =3D '1', $4 =3D NULL, $5 =3D =
'1398290328'
2014-04-23 23:58:48 CEST [63584]: [50-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.051 ms  parse <unnamed>: SELECT "Service"."name" FROM =
"Service" INNER JOIN "Host" ON "Host"."serviceRef"=3D"Service"."id" =
WHERE "Host"."id"=3D$1
2014-04-23 23:58:48 CEST [63584]: [51-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.117 ms  bind <unnamed>: SELECT "Service"."name" FROM =
"Service" INNER JOIN "Host" ON "Host"."serviceRef"=3D"Service"."id" =
WHERE "Host"."id"=3D$1
2014-04-23 23:58:48 CEST [63584]: [52-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D '4'
2014-04-23 23:58:48 CEST [63584]: [53-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.049 ms  execute <unnamed>: SELECT "Service"."name" =
FROM "Service" INNER JOIN "Host" ON "Host"."serviceRef"=3D"Service"."id" =
WHERE "Host"."id"=3D$1
2014-04-23 23:58:48 CEST [63584]: [54-1] user=3Dreslist,db=3Dreslist =
DETAIL:  parameters: $1 =3D '4'
2014-04-23 23:58:48 CEST [63584]: [55-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.021 ms  parse S_1: COMMIT
2014-04-23 23:58:48 CEST [63584]: [56-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.013 ms  bind S_1: COMMIT
2014-04-23 23:58:48 CEST [63584]: [57-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.226 ms  execute S_1: COMMIT
2014-04-23 23:58:48 CEST [63576]: [48-1] user=3Dreslist,db=3Dreslist =
ERROR:  duplicate key value violates unique constraint =
"QueueLowerEmailIdx"
2014-04-23 23:58:48 CEST [63576]: [49-1] user=3Dreslist,db=3Dreslist =
DETAIL:  Key (lower(email::text))=3D(silberbatzen@gmail.com) already =
exists.
2014-04-23 23:58:48 CEST [63576]: [50-1] user=3Dreslist,db=3Dreslist =
STATEMENT:  INSERT INTO =
"VerifyQueue"("email","token","userRef","groupRef","creationTime") =
VALUES ($1,$2,$3,$4,$5)
2014-04-23 23:58:48 CEST [63584]: [58-1] user=3Dreslist,db=3Dreslist =
LOG:  disconnection: session time: 0:00:00.023 user=3Dreslist =
database=3Dreslist host=3D127.0.0.1 port=3D62259
2014-04-23 23:58:48 CEST [63576]: [51-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.036 ms  parse S_1: ROLLBACK
2014-04-23 23:58:48 CEST [63576]: [52-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.010 ms  bind S_1: ROLLBACK
2014-04-23 23:58:48 CEST [63576]: [53-1] user=3Dreslist,db=3Dreslist =
LOG:  duration: 0.011 ms  execute S_1: ROLLBACK
2014-04-23 23:58:48 CEST [63576]: [54-1] user=3Dreslist,db=3Dreslist =
LOG:  disconnection: session time: 0:00:00.044 user=3Dreslist =
database=3Dreslist host=3D127.0.0.1 port=3D62251

claudio
--=20
Claudio Nieder  .  mailto:claudio.nieder@inodes.ch  .  http://inodes.ch/
iNodes AG  .  Loogartenstrasse 14  .  CH-8048 Z=FCrich  .  +41 43 960 =
0066