Support for Drupal 7 is ending on 5 January 2025—it’s time to migrate to Drupal 10! Learn about the many benefits of Drupal 10 and find migration tools in our resource center.
I ran into a race condition which generated a database warning on one of my pages, but firefox crashed before I hit submit on the bug report here.
Oh, I know, it might be in my logs. I'll go look.
The sequence of page loads that led to the race was:
1. load a page while logged in
(wait)
then roughly concurrently:
2. hit logout on that page
3. open a new tab and load the home page (configured to not point at "node" anymore) in that tab
I'll go look in the logs to see if I can get the exact error.
Comment | File | Size | Author |
---|---|---|---|
#19 | sessions.patch | 1.26 KB | moshe weitzman |
#16 | session_optimize_0.patch | 4.27 KB | moshe weitzman |
#15 | session_optimize.patch | 3.68 KB | rkerr |
#7 | 44947.patch | 708 bytes | Wesley Tanaka |
Comments
Comment #1
Wesley Tanaka CreditAttribution: Wesley Tanaka commentedUnfortunately, it seems like the logs only have the second warning (the one about headers already sent), but not the database one. It's not in my firefox disk cache either.
However, it seems that there's only one place in the codebase where an INSERT is called on the {sessions} table, in includes/session.inc.
That line generated a duplicate key warning.
Comment #2
Zen CreditAttribution: Zen commentedComment #3
Wesley Tanaka CreditAttribution: Wesley Tanaka commentedThe bug is here:
Both SELECTs get run simultaneously, and return no results. Then both INSERTs get run with the same session id, and one of them generates an error.
Comment #4
jvandyk CreditAttribution: jvandyk commentedI don't think I see a good solution to this. We could lock the session table every time we did a session read in case we need to do an insert before the second request did a read, but I imagine the performance hit on MyISAM would be unacceptable.
The error seems to have cropped up several times:
17825
21120
I don't understand why increasing the length of sid from 32 to 64 characters helped, as PHPSESSID's are always a 32 character md5 hash.
Comment #5
Wesley Tanaka CreditAttribution: Wesley Tanaka commentedjvandyk,
Thanks for your contribution.
Neither 17825 nor 21120 appears to be referring to this race condition, which I don't even know exists or not in those earlier code bases. Forum post 21120 is an issue that occurred every time the user logged in, as opposed to this race condition, which does not appear all the time. Bug 17825 is an insertion of sid=0. It's extrememly improbable (or perhaps impossible) that such a session id would be generated and passed into sess_read.
Both also appear from the comments like they have been resolved. This issue has not been.
There are many solutions to this. Perhaps what you are saying is that you don't see any good solutions to this that could be encoded into a 2 or 3 line patch.
Comment #6
Wesley Tanaka CreditAttribution: Wesley Tanaka commentednode_tag_new solves a similar race condition by prefixing the insert db_query with a '@'.
Comment #7
Wesley Tanaka CreditAttribution: Wesley Tanaka commentedThis patch adds a '@' before the insert db_query, which I believe is supposed to suppress the warning that comes about if sess_read gets called twice simultaneously. Both simultaneously-run inserts i should be inserting the same values (time() for the two calls might be slightly different), in which case it is safe to ignore the duplicate insert warning.
Comment #8
Wesley Tanaka CreditAttribution: Wesley Tanaka commentedComment #9
Wesley Tanaka CreditAttribution: Wesley Tanaka commenteds/inserts i should/inserts should/
Comment #10
markus_petrux CreditAttribution: markus_petrux commentedI'm not sure to understand the problem. According to the PHP manual:
http://www.php.net/session_write_close
Comment #11
markus_petrux CreditAttribution: markus_petrux commentedAn interesting bug report "Session (concurrency ?) problem", marked as bogus.
hmmm...
Comment #12
Dries CreditAttribution: Dries commentedMaybe session_write_close() holds a lock. Clearly, session_read() does not. :)
Comment #13
markus_petrux CreditAttribution: markus_petrux commentedI believe part of the solution would be to rewrite the session handlers. Probably helps moving the access to the user record off these session handlers.
Comment #14
rkerr CreditAttribution: rkerr commentedWhy do we do inserts in sess_read, instead of sess_open?
Comment #15
rkerr CreditAttribution: rkerr commentedWent through this with moshe, and figured that we probably shouldn't be doing any database writes in sesss_read. This patch should avoid the race condition by doing the db inserts in the "proper" place (sess_write), as well as optimizing sessions for anonymous users by only creating session data for them when there is _really_ some data to be stored (not just messages).
It doesn't seem to break any functionality :) and supports a user transitioning from being not logged in to logged in and maintaining their session data (not completely sure if that happened before or not).
Please review and test!
Comment #16
moshe weitzman CreditAttribution: moshe weitzman commentedBroke out a query in sess_read() to speed things up a little for anon users. Added some code comments.
This patch represents a massive speedup and memory improvement for Drupal. The sessions table will get much smaller, and we avoid an expensive insert for most anon users. Yet we offer anon sessions when a module wants to use them (e.g. comment control panel).
Comment #17
Dries CreditAttribution: Dries commentedTested. Committed to HEAD. Great patch.
Comment #18
moshe weitzman CreditAttribution: moshe weitzman commentedI added some module updating info to http://drupal.org/node/22218#sessions. Also, this patch broke the user block where we report the number of anon users currently on the site. I plan to remove that info from the block, unless someone comes up with a better solution.
Comment #19
moshe weitzman CreditAttribution: moshe weitzman commentedIn addiiton to Who's Online, we crippled the throttle module. So i'm scaling back the optimization. This patch records session records for anon users too. The only exception are anon users without cookies. Those get no session record unless a module requests it. This helps keep crawlers from spawning thousands of useless sessions.
Comment #20
killes@www.drop.org CreditAttribution: killes@www.drop.org commentedCan't we make throttle module and the user block specifically request a session for anon users with cookies? I don't use neither the block not the module and would want to have the complete optimization.
Comment #21
Dries CreditAttribution: Dries commentedI committed Moshe's last patch but am not marking this fixed yet. Maybe a better solution arises. Also, it looks like that if-test could be simplified now?
Comment #22
Wesley Tanaka CreditAttribution: Wesley Tanaka commentedSo what's the consensus on putting a '@' before the insert db_query call?
Comment #23
Cvbge CreditAttribution: Cvbge commentedUsing @db_query() does nothing. You can test this by creating simple table with unique column and then creating a block with php code which does inserts a value. On second refresh you'll still see the error.
This is due to this http://pl2.php.net/manual/en/function.set-error-handler.php:
So we'd have to check error_reporting inside of error_handler.
Comment #24
markus_petrux CreditAttribution: markus_petrux commentedOh, yes, please do.
See this:
http://drupal.org/node/41209
Comment #25
moshe weitzman CreditAttribution: moshe weitzman commentedComment #26
Wesley Tanaka CreditAttribution: Wesley Tanaka commentedvia inspection of session.inc 1.26, the originally reported problem has not been addressed
Comment #27
moshe weitzman CreditAttribution: moshe weitzman commentedwe fixed a more serious race condition. the one you mention requires multiple simultaneous browser windows with a logout action. extremely rare to the point of "not worth it". moving back to fixed since we did improve session hadnling a lot and i don't want this issue permanently logged as won't fix.
Comment #28
Wesley Tanaka CreditAttribution: Wesley Tanaka commentedThis is the problem with one issue report meaning two different things.
Split the issue. This issue is retroactively for tracking the patches that have already been committed.
http://drupal.org/node/52662 is for the race condition. Let's move the discussion about that issue's status there.
Comment #29
(not verified) CreditAttribution: commented