Upgraded from Beta 4 -> RC2 last weekend. At the same time, changed configuration for caching and turned block cache off -> on. Today opened front page, noticed that the login block was missing and instead displayed the user name of previously logged-on user. Was unable to access user's account data, i.e. the session context wasn't leaked, only the output from the login box.

Tried to reproduce the problem on a separate fresh install of RC2. (Created one account in addition to admin, turned block cache on and attempted to logon/logoff with the second account and monitoring behaviour for anonymous user.) Wasn't able to reproduce the behaviour on the second box.

Continued investigating the block cache issue: Turned block caching back on. Logged on to the site, and noticed that the "User login" block was not in sync with my session, i.e. was still displaying the form requesting me to log in.

Any suggestions on how to debug this? I'm not familiar with core enough to locate the problem by myself. The site in question is live and public, so anybody interested can contact me for a "remotely assisted" debugging session of some sort (I'd be watching and reporting the variables from Drupal according to suggestions.)

Could be a security risk, i.e. reveal user-sensitive data. Not sure if priority "critical" is appropriate for the issue.

Comments

htalvitie’s picture

Title: User login block displays stale or inconsistent data when block cache is turned on » Block displays stale or inconsistent data when block cache is turned on

The problem doesn't seem to be related only to the user login block. Since the same issue came up with the navigation block too, I removed "user login (block)" from the title.

htalvitie’s picture

Version: 6.0-rc2 » 6.x-dev
Component: base system » install system
Status: Active » Needs review
StatusFileSize
new1.46 KB

As far as I can tell, during a fresh installation of Drupal 6 RC2, system.install populates incorrect values in the blocks table.

At some point, a new column for specifying the caching was added to the blocks table. The new cache column gets value 1 as default which translates to BLOCK_CACHE_PER_ROLE.

The updater function system_update_6027() in system.install assigns cache values for existing rows according to the block declarations in already installed modules. The user module declares blocks "Log In" and "Navigation" with cache setting BLOCK_NO_CACHE (maps to -1) .

The current system.install does not specify values when creating rows for "Log In" and "Navigate" blocks so they are defined as BLOCK_CACHE_PER_ROLE.

So at the end, when the site administrator turns on the page and block caching, all "Log In" and "Navigate" blocks are cached on role-by-role basis and all authenticated users will see the latest cached block from whoever happens to produce it.

The reason I was not able to reproduce this earlier was because I had user = 1 as the second tester. The block caching treats user 1 differently.

This patch adds the BLOCK_NO_CACHE (-1) values to the system.installer, so now the initial values for a new Drupal 6 installation are correct.

The database updater might need additional code to change the cache setting from 1 -> -1 for existing RC2-based installations?

catch’s picture

Title: Block displays stale or inconsistent data when block cache is turned on » RC3 blocker: Block displays stale or inconsistent data when block cache is turned on
Priority: Normal » Critical

Displaying the user login block when users are already logged in sounds critical to me.

calebgilbert’s picture

I dunno about the most down and dirty specifics of the core block caching methods, but after a year and a half of using the blockcache module religiously I can definitely say for sure that anything with input fields is a 100% no-no with block caching.

yched’s picture

StatusFileSize
new3.58 KB

OK, I think I remember that when block cache was written, _block_rehash() used to wipe the entire {blocks} table, and rewrite all the rows. Thus, the correct 'cache_mode' values got inserted the first time the admin visited the block admin page.
Putting a site live without ever once visiting block admin being unlikely, this was admittedly OK

_block_rehash() has since then been rewritten to be smarter about delete/inserts, but the rows inserted in system_install() never get a chance to get their 'cache_mode' value from their implementing module

Same patch as #2 by htalvitie above, with an update function to fix existing RC installs (we're supposed to support RC to RC upgrades, right ?).
It also disables caching for the 'Powered by Drupal' block, that definitely is one of those too simple blocks for which caching would rather add overhead.

@CalebG : The block cache system takes care of not fetching from the cache when request method is POST. No incompatibility per se between forms and caching. Or else, page caching would also prevent anonymous users from submitting forms :-)

Bence’s picture

I experienced something similar with Drupal 5.5, but it was about 1 month ago. Maybe should check whether this bug does exist in D5 or not.

Bence’s picture

Maybe I don't understand fully this issue, but the web browser use also a cache. What happens if you refresh (Ctrl+R) the wrong displayed page with the browser, does the problem still exist?

yched’s picture

@Bence :
- Drupal 5 doesn't have block caching, so the issue doesn't apply there.
[edit : unless using contrib module Block Cache, of course, but then it's not a core issue and has little chance to be related]
- This is server-side caching ("do we need to rebuild the block content from scratch, or can we simply serve the HTML snippet stored from a previous page view"), and is completely unrelated to browser caching. If server cache logic is flawed, hitting CTRL-F5 will give you the same erroneous content.

Anyway, the patches here do fix the issue.

birdmanx35’s picture

Status: Needs review » Reviewed & tested by the community

I just tested this patch and it applies cleanly to HEAD, and it seems to fix the issue.

gábor hojtsy’s picture

Status: Reviewed & tested by the community » Needs review

birdmanx35: how did you verify that the patch does what it supposed to do?

catch’s picture

I'm unable to reproduce the original bug. Patch doesn't do any harm though.

gábor hojtsy’s picture

Status: Needs review » Fixed

So looks like the patch makes user/0 = login, user/1 = navigation and system/0 = powered by Drupal all not cached when being inserted the first time. While the first two had that defined in code already, the third one gets it in the code with this patch as well. Since it is important initialization code to do even for cases when the user does not visit the blocks page but turns on block caching right away (seeing his not-to-be-cached blocks cached), this is important to fix. It all looks good in the patch upon review as well, and catch verified it does not do any harm, so committed, thanks.

htalvitie’s picture

Status: Fixed » Needs work

@yched: Unfortunately the proposed patch isn't complete and the schema updater is broken.

After applying the patch, the function system.install.system_update_6047() contains 3 rows like these:

$ret[] = update_sql("UPDATE {blocks} SET cache = %d WHERE module = '%s' AND delta = '%s'", -1, 'user', '0');

.. etc.

When I checked the documentation and contents of update_sql(), I noticed that %-substitution parameters are not supported.

This explains the output from running the update.php?op=results:

The following queries were executed

system module

Update #6047

  • UPDATE {blocks} SET cache = %d WHERE module = '%s' AND delta = '%s'
  • UPDATE {blocks} SET cache = %d WHERE module = '%s' AND delta = '%s'
  • UPDATE {blocks} SET cache = %d WHERE module = '%s' AND delta = '%s'

I was surprised, because no errors were reported back to the UI even when the commands are not valid SQL and typed manually produce an error message from MySQL:

Error Code : 1064
You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near '} SET cache = %d WHERE module = '%s' AND delta = '%s'' at line 1

When I debugged the code, I noticed the actual SQL commands that got finally passed to MySQL were not those shown above, but instead they were futher altered by a callback function in database.mysql-common.inc at line 41:

$query = preg_replace_callback(DB_QUERY_REGEXP, '_db_query_callback', $query);

The callback performs some search-replace operations based on the %s and %d placeholders. Since the placeholders haven't been properly passed anywhere, the final UPDATE query is:

UPDATE blocks SET cache = 1 WHERE module = '' AND delta = ''

This isn't invalid SQL, so it doesn't trigger an error.

(I think there is a separate issue needed to make the update_sql() function in database.inc safer. It should not accept variable argument calls, if it can't forward those to db_query anyway.)

Additionally, I think the proposed patch is missing a "ALTER TABLE" command needed to change the default value for blocks.cache from 1 to -1.

gábor hojtsy’s picture

Gosh, indeed, update_sql() does not support placeholders at all. However, we are not changing defaults on the cache field. Having a default of 1 there was intentional. Block caching is op-out, not opt-in.

Grm, so get these update_sql()s fixed before an RC3.

htalvitie’s picture

Indeed, my last observation about the default value for blocks.cache was incorrect.

I must have been confused by the addition of 'cache' => BLOCK_NO_CACHE to system.module, but that code was of course unrelated to the schema.

gábor hojtsy’s picture

Status: Needs work » Fixed
StatusFileSize
new1 KB

Committed the attached fix.

htalvitie’s picture

Upgraded my RC2 to RC3, then compared full db SQL dumps before & after.

system_update_6047() worked. Looks fine to me.

Anonymous’s picture

Status: Fixed » Closed (fixed)

Automatically closed -- issue fixed for two weeks with no activity.