PostgreSQL: Database error when creating new user with attributes

[Oliver Metz]

Hi.

We are running trac-0.12.3 with postgres db. Since one of the last updates of account manager plugin users cause this error message when creating a new account:

2011-08-10 08:33:05,339 Trac[api] INFO: Created new user: foobar
2011-08-10 08:33:05,370 Trac[main] ERROR: Internal Server Error:.
Traceback (most recent call last):
  File "/usr/local/lib/python2.6/dist-packages/Trac-0.12.3dev_r10719-py2.6.egg/trac/web/main.py", line 522, in _dispatch_request
    dispatcher.dispatch(req)
  File "/usr/local/lib/python2.6/dist-packages/Trac-0.12.3dev_r10719-py2.6.egg/trac/web/main.py", line 243, in dispatch
    resp = chosen_handler.process_request(req)
  File "build/bdist.linux-i686/egg/acct_mgr/web_ui.py", line 439, in process_request
    _create_user(req, self.env)
  File "build/bdist.linux-i686/egg/acct_mgr/web_ui.py", line 154, in _create_user
    set_user_attribute(env, username, attribute, value)
  File "build/bdist.linux-i686/egg/acct_mgr/api.py", line 581, in set_user_attribute
    """, (username, attribute, value))
  File "/usr/local/lib/python2.6/dist-packages/Trac-0.12.3dev_r10719-py2.6.egg/trac/db/util.py", line 65, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
IntegrityError: insert or update on table "session_attribute" violates foreign key constraint "fk_session_sid"
DETAIL:  Key (sid)=(foobar) is not present in table "session".
IntegrityError: insert or update on table "session_attribute" violates foreign key constraint "fk_session_sid"
DETAIL:  Key (sid)=(foobar) is not present in table "session".

This happens only when one of the additional fields (name, email) is filled out. Otherwise everything ist fine. Despite the error message the user is created.

Do you have an idea what is going on here?

Regards
Oliver

p.s. Thank you for your great work on this plugin.

[Steffen Hoffmann]

Replying to olistudent:

We are running trac-0.12.3 with postgres db. Since one of the last updates of account manager plugin users cause this error message when creating a new account:
(snip)
This happens only when one of the additional fields (name, email) is filled out. Otherwise everything ist fine. Despite the error message the user is created.

Do you have an idea what is going on here?

Yes I do, this fit's perfectly with the changes in [10520], as you may see yourself from the commit message there.

I wasn't aware of the use of sid column from Trac db table session as a db table key, since this isn't the case with SQLite backend. Even more I meant adding a fake session is obsolete, since I tested and it's created on first login anyway. So I left it out starting with aforementioned changeset, and now - consequently - your PostgreSQL misses the sid = foreign key (obviously required from your db schema) when trying to insert any user attributes (to session_attribute) on registration time.

Password is still set, so bare user credentials are "created". After first login the expected sid gets added by Trac core to db table session, and everything is fine then, you see?

So now I understand the need and will revert that change ASAP.

And of course you're welcome regarding your appreciation of my maintenance work. Great to have followers/testers/users like you, that help to improve by meaningful reports. So thank you too.

[Steffen Hoffmann]

Beware: User attributes will be set againg after reverting changeset [10520], but will still not be shown before first login in the users (accounts) admin page. This is another issue, I'm already aware of. See another comment at #9051 and follow there, if you care.

[Steffen Hoffmann]

I meant comment 5 for #9051, sorry

[Steffen Hoffmann]

(In [10585]) AccountManagerPlugin: Almost revert changeset [10520], refs #9079.

Continue to add a fake user session to enable use of sid column in Trac db table session as foreign key as required by some db schemata (not SQLite). This re-enables setting user attributes to Trac db table session_attribute on registration time, i.e. for PostgreSQL compatibility. But beware, the session added on registration is no longer marked as 'authenticated'.

[Oliver Metz]

The error still occurs. Can you please post 2-3 lines of debugging code to add? So we can see what is going on in changes from r10585.

[Steffen Hoffmann]

diff between r10585 and r10519 (reversed)

[Steffen Hoffmann]

1st patch​ is about making sure, the remaining difference is not responsible for the still bad behavior.

[Steffen Hoffmann]

debug output and more for testing as requested

[Steffen Hoffmann]

2nd patch​ has some debug lines (roughly estimated about as much as you requested ;-). Pay attention to the following commented-out line too:

#db.commit()

I suggest you try to uncomment it for another test, since I figured out the new user entry might just not get committed to the db before the other, transaction (adding attributes - this is not atomic by intention) happens.

While I don't expect all this debug stuff to resolve it magically, it should at least push the matter bit further. Thank you very much in advance for testing.

[Oliver Metz]

Tested with temp.patch applied, debug.patch applied and uncommented commit line. None of them works. Log is from last version with all patches:

2011-09-03 10:33:34,107 Trac[api] INFO: Created new user: test
2011-09-03 10:33:34,108 Trac[web_ui] WARNING: _create_user: user exists? (0L,)
2011-09-03 10:33:34,120 Trac[main] ERROR: Internal Server Error:.
Traceback (most recent call last):
  File "/usr/local/lib/python2.6/dist-packages/Trac-0.12.3dev_r10719-py2.6.egg/trac/web/main.py", line 522, in _dispatch_request
    dispatcher.dispatch(req)
  File "/usr/local/lib/python2.6/dist-packages/Trac-0.12.3dev_r10719-py2.6.egg/trac/web/main.py", line 243, in dispatch
    resp = chosen_handler.process_request(req)
  File "build/bdist.linux-i686/egg/acct_mgr/web_ui.py", line 476, in process_request
    _create_user(req, self.env)
  File "build/bdist.linux-i686/egg/acct_mgr/web_ui.py", line 191, in _create_user
    set_user_attribute(env, username, attribute, value)
  File "build/bdist.linux-i686/egg/acct_mgr/api.py", line 583, in set_user_attribute
    """, (username, attribute, value))
  File "/usr/local/lib/python2.6/dist-packages/Trac-0.12.3dev_r10719-py2.6.egg/trac/db/util.py", line 65, in execute
    return self.cursor.execute(sql_escape_percent(sql), args)
IntegrityError: insert or update on table "session_attribute" violates foreign key constraint "fk_session_sid"
DETAIL:  Key (sid)=(test) is not present in table "session".
IntegrityError: insert or update on table "session_attribute" violates foreign key constraint "fk_session_sid"
DETAIL:  Key (sid)=(test) is not present in table "session".

[Steffen Hoffmann]

Replying to olistudent:

Tested with temp.patch applied, debug.patch applied and uncommented commit line. None of them works. Log is from last version with all patches: ![...]

Ok, you see it: The user (sid) is not seen in the session table when attempting to add some attributes for it to the session_attribute Trac db table. Why it fails (silently) is still beyond my imagination. To prove, it really is (not) there, is the next step.

I've checked several possibilities ahead, but I'm afraid there's no such thing like a shortcut in sight right now. Further step-by-step approach instead, and I'll provide the next patch to continue with, again purely for debugging purposes.

[Oliver Metz]

I assume the problem is here: 2011-09-03 10:33:34,108 Trac[web_ui] WARNING: _create_user: user exists? (0L,)

So the fix should be this?

acct_mgr/web_ui.py

@@ -157 +157 @@
         WHERE   sid=%s
         """, (username,))
     exists = cursor.fetchone()
-    if not exists:
+    if not exists[0]:
         cursor.execute("""
             INSERT INTO session
                     (sid,authenticated,last_visit)

[Steffen Hoffmann]

Sure, silly me.

The cursor results are always wrapped, even if it's a single item. So your solution is correct. I've checked with SQLite here; fails/works without/with the indexed item expression too. Must be due to not using foreign keys in the db schema, why I've never noticed this before. Bless god we have PostgreSQL. And at least the debug code has been sufficient to detect the flaw. ;-)

[Steffen Hoffmann]

(In [10660]) AccountManagerPlugin: Fix a test in the _create_user function, refs #9079.

Despite of initial rumor this has never been a PostgreSQL compatibility issue. Only usage of foreign keys in the db schema has made the bug more visible. Thanks to Oliver for good suggestion and much patience while testing.

[Steffen Hoffmann]

(In [11826]) AccountManagerPlugin: Hotfix for pending user-registration issue, refs #9079, #9252, #9843 and #9090.

Now the reversion of [10520] done by [10585] is completed, although there are many related changes and improvements in-between, so this is not quite the same code as before.

Taking the chance to update now obsolete configuration examples in README too.

This has already open for much too long, so let's ditch the rather esoteric considerations of authenticated user entries in Trac db table session for now and move on.

Big sorry, that this took that much time, and thanks to Peter Stuge for finally pushing me to it tonight.

[Steffen Hoffmann]

(In [12398]) AccountManagerPlugin: Releasing version 0.4, pushing development to acct_mgr-0.5dev.

Availability of that code as stable release closes #874, #3459, #4677, #5295, #5691, #6616, #7577, #8076, #8685, #8770, #8791, #8990, #9052, #9079, #9090, #9139, #9246, #9252, #9547, #9618, #9676, #9843, #9852, #9940, #10023, #10028, #10123, #10142, #10204, #10276, #10397, #10412, #10594, #10625 and #10644.

Some more issues have been worked-on, yet without confirmed resolution, refs #5464 (for JiraToTracIntegration), #8927 and #10134.

And finally there are some issues and enhancement requests showing progress, but known to require more work to resolve them satisfactorily, refs #843, #1600, #5964, #8217, #8933.

Thanks to all contributors and followers, that enabled and encouraged a good portion of this development work.