Drupal messages (status/error) are cached along with nodes

Pinolo@www.drup... - August 20, 2007 - 14:24
Project:Drupal
Version:7.x-dev
Component:base system
Category:bug report
Priority:critical
Assigned:Unassigned
Status:patch (reviewed & tested by the community)
Description

If a module sends out a message and then Drupal redirects to a page that be cached, the message shown on that page is cached too.
Steps to reproduce (example):
[as an admin]

  • activate the contact module and set things up so that the contact form is available to anonymous users
  • activate caching in normal mode
  • make sure your default page in site configuration is a node (not "node", but "node/1", "node/23", etc.)

[as anonymous user (ex. using another browser and not logging in)]

  • visit the contact form and send a message
  • you are now redirected to the default page, where a confirmation message appears ("Your message ave been sent")
  • reload the page with the browser's reload button
  • you shouldn't see now the message, but you see it again
  • visit the site as another anonymous user (use another browser, or another PC)
  • you'll see the message even if you're another anonymous user

After, you've followed these steps, you can go back to administration and update the node you defined as default page: you'll see that the message disappears from the anonymous user view. So, caching works as expected, only it shouldn't cache messages with nodes.

For the contact form, the issue is just a little more than a visual annoyance; but if you use Simplenews and allow anonymous users to subscribe, the latest subscription confirmation (with the e-mail address of the subscriber) remains visible to al anonymous visitors of the default page (ugly!).

http://drupal.org/node/150852 shows that the issue dates at least back to 5.1

This happens to me on Apache 2, PHP 5.2.2, MySQL 5.0.24

#1

flevour - August 20, 2007 - 16:52

Alas, after following your instructions carefully, I can't reproduce this bug.
Even with aggressive caching turned on things work smoothly (reloading home page makes message disappear).
It looks like a browser+server+other_unguessable_variables issue to me. Since things work as expected in the vast majority of the cases, I'd look into some $_SESSION handling issues (?). You may try to var_dump($_SESSION) at the end of each page load and see what goes? But this wouldn't explain the cross-browser part of the issue...

I am running PHP 5.2.1 and Apache 2.2.3 Multi-Processing Module (MPM) (in ubuntu).

Unreproducible bugs are weird, anyway.

#2

Pinolo@www.drup... - August 20, 2007 - 21:16

I have 2 sites on the same Drupal installation. Both have a very basic setup. One shows the problem, the other doesn't. I have also verified this is not theme (template.php) related, since I was able to reproduce the bug with the stock Garland. I have also verified the settings.php files and they're identical, except for the db connection line.
The core is an unpatched 5.2 checked out from CVS, modules are all from the 5 branch of contrib.

Modules enabled for the installation WITH issue

Core (opt)
Color
Comment
Contact
Help
Locale
Menu
Upload

Mail
Mime Mail
Simplenews

Other
FCKeditor

Views
Views
Views RSS
Views Th. Wiz
Views UI

Modules enabled for the installation WITHOUT issue

CCK
Content Templates
Content
Content Copy
Date
Fieldgroup
Image
Option Widgets
Text

Core (opt)
Comment
Contact
Locale
Menu
Path
Taxonomy
Upload

Other
BUEditor
Taxonomy Context
TinyMCE

Views
Views
Views RSS
Views Th. Wiz
Views UI

#3

coreyp_1 - January 3, 2008 - 13:49
Version:5.2» 5.5
Priority:normal» critical

I can confirm the bug. My forum post can be found here.

In my post, I mention that I cannot reproduce the bug on my localhost (possibly because it cannot send e-mails), but I can reliably re-create it on my web host.

This would seemingly be a critical bug, because cache is, in essence, broken.

It may only be manifesting itself when the front page is a node, rather than a module-generated pages.

#4

kndr - February 9, 2008 - 13:17

I've got this bug in clean instalation of Drupal 6.0-rc4. Here is an issue http://drupal.org/node/219652

#5

catch - February 9, 2008 - 13:40
Version:5.5» 6.x-dev

http://drupal.org/node/219652 was duplicate. See also this forum report: http://drupal.org/node/205521

Moving to 6.x - bugs get fixed in the development release then back ported.

#6

chx - February 9, 2008 - 15:07
Status:active» patch (code needs review)
AttachmentSize
pgsc.patch1.36 KB

#7

kndr - February 9, 2008 - 17:03

#6 works for me in Drupal 6.0-rc4. Great! I've just also tested it on Drupal 5.x with Simplenews and it works too. Very good news!

#8

chx - February 9, 2008 - 17:52
Status:patch (code needs review)» patch (reviewed & tested by the community)

Then it's RTBC.

#9

moshe weitzman - February 10, 2008 - 01:59

@chx - can you explain whats wrong with the current code that it causes thus bug? your new code looks good but i am missing the "why".

#10

chx - February 10, 2008 - 02:41

I suspect some php goof here , we basically used ob_get_contents as our gatekeeper which apparently fails. I instead pass a flag "yes i did start ob!" and then recounting messages is not needed at all. Even the request method is not absolutely necessary but I left it in as a sneaky hacky way to stop page set cache for whatever reason.

#11

Gábor Hojtsy - February 11, 2008 - 11:48
Status:patch (reviewed & tested by the community)» patch (code needs work)

page_get_cache() already checks for uid and the GET method, so this looks like some code duplication there. (If not for micro optimized speed, to avoid a function call, then I don't see why to do it). Even if the page was cached, page_get_cache() should return FALSE under these conditions with uid != 0 or !GET.

#12

Gábor Hojtsy - February 11, 2008 - 12:00
Status:patch (code needs work)» patch (code needs review)

Here is an updated patch with some phpdoc improvements as well. Please test.

AttachmentSize
pgsc_2.patch1.71 KB

#13

kndr - February 11, 2008 - 13:00

#12 works good in my Drupal 6.x and 5.x instalations .

#14

chx - February 11, 2008 - 13:03

Hm, I left in the user uid checking because you might get logged in during the page run and I left in the request method caching as I stated above so that there is a sneaky way of disabling page set cache just in case. Not a terrible code duplication, I say.

#15

Gábor Hojtsy - February 11, 2008 - 13:12
Version:6.x-dev» 7.x-dev
Status:patch (code needs review)» patch (reviewed & tested by the community)

Indeed, the user might have been logged in since the request started. OK, brought these two conditionals back. Thanks kndr for retesting. Committed the attached one. RTBC for 7.x as well.

AttachmentSize
pgsc_3.patch.txt1.76 KB

#16

Arancaytar - February 11, 2008 - 13:13
Version:7.x-dev» 6.x-dev
Status:patch (reviewed & tested by the community)» patch (code needs review)

How would you sneakily disable it - by setting REQUEST_METHOD to something other than GET manually?

Also, is your complaint with #12 that the status gets stored statically and checked only once?

#17

Arancaytar - February 11, 2008 - 13:13
Version:6.x-dev» 7.x-dev
Status:patch (code needs review)» patch (reviewed & tested by the community)

Cross-post.

#18

chx - February 11, 2008 - 13:17

Exactly, by setting REQUEST_METHOD. It is a hack, but how often do we need page_set_cache disabled? Extremely rarely so we do not need a full fledged API to disable it but leaving a catdoor open is good.

#19

kndr - February 11, 2008 - 13:50

Ouch! Did you check cache_page table? There is no records, no cached pages! Sorry. I did not check this. It looks that cache is turned off by this patch. Am I wrong?

#20

Arancaytar - February 11, 2008 - 13:51

Do you mean {cache_page}? I will test to see if I can reproduce this.

#21

Arancaytar - February 11, 2008 - 14:00
Version:7.x-dev» 6.x-dev
Status:patch (reviewed & tested by the community)» patch (code needs work)

Reproduced, alas. Page cache mode is set to normal, I am browsing as an anonymous user, and try as I might I cannot get {cache_page} to gain any records.

Edit: Aggressive caching with minimum lifetime of one day makes no difference either. I will add some debugging output to trace this issue...

#22

Arancaytar - February 11, 2008 - 14:16

Odd. Adding a var_dump call to the function has produced bool(true) at the start and end of the page (expected), and also I now have a record in {cache_page}.

I hate it when this happens. Trying to remove the var_dump again to see if this really does it. If it does, I am stumped.

Edit: s/page_cache/cache_page

#23

Arancaytar - February 11, 2008 - 14:23

Well, good news (good?) and bad news:

1.) {cache_page} is indeed only filled with the following code:

<?php
function page_get_cache($status_only = FALSE) {
  static
$status = FALSE;
  global
$user, $base_root;

 
$cache = NULL;

  if (!
$user->uid && $_SERVER['REQUEST_METHOD'] == 'GET' && count(drupal_set_message()) == 0) {
   
$cache = cache_get($base_root . request_uri(), 'cache_page');

    if (empty(
$cache)) {
     
ob_start();
     
$status = TRUE;
    }
  }

  echo
"test"; // the {cache_page} table will only be filled if this line is here.

 
return $status_only ? $status : $cache;
}
?>

2.) {cache_page} will contain "test". Nothing else.

Perhaps we're inadvertently closing the output buffer somewhere before output is actually started?

Edit: s/page_cache/cache_page

Edit2:

Might this do it?

<?php
function page_get_cache($status_only = FALSE) {
  static
$status = FALSE;
  global
$user, $base_root;

 
$cache = NULL;

  if (!
$user->uid && $_SERVER['REQUEST_METHOD'] == 'GET' && count(drupal_set_message()) == 0) {
   
$cache = cache_get($base_root . request_uri(), 'cache_page');

    if (!
$status && empty($cache)) { // only start the buffer once.
     
ob_start();
     
$status = TRUE;
    }
  }

  return
$status_only ? $status : $cache;
}
?>

Or this?

<?php
function page_get_cache($status_only = FALSE) {
  static
$status = FALSE;
  global
$user, $base_root;

 
$cache = NULL;

  if (!
$user->uid && $_SERVER['REQUEST_METHOD'] == 'GET' && count(drupal_set_message()) == 0) {
   
$cache = cache_get($base_root . request_uri(), 'cache_page');

    if (!
$status_only && empty($cache)) { // only start the buffer if we are not just returning the status.
     
ob_start();
     
$status = TRUE;
    }
  }

  return
$status_only ? $status : $cache;
}
?>

I got this weird suspicion we may be starting the buffer twice.

#24

Arancaytar - February 11, 2008 - 14:29
Status:patch (code needs work)» patch (code needs review)

I've solved the problem by using !$status as in the second of the three code blocks above. page cache now works as advertised.

I don't know the policy here. Do we have to roll-back and re-roll the complete patch, or is it enough to tack on this new fix in a separate patch?

Here it is, anyway.

AttachmentSize
bootstrap-fix-page-cache-168909-24.patch677 bytes

#25

chx - February 11, 2008 - 14:30
Status:patch (code needs review)» patch (reviewed & tested by the community)
AttachmentSize
x.patch768 bytes

#26

catch - February 11, 2008 - 14:33
Status:patch (reviewed & tested by the community)» patch (code needs review)

looks like a cross post to me.

#27

Arancaytar - February 11, 2008 - 14:36

(This is a cross-post too, but luckily I got the email alert and can keep the status updated in this form...)

I guess either of these fixes work. Just to be safe, however, why not check the $status as well (as mine does)? If we're already paranoid about ob and setting our own flag, we might as well prevent ourselves from starting ob more than once by actually using the flag there.

#28

Gábor Hojtsy - February 11, 2008 - 14:41
Version:6.x-dev» 7.x-dev
Status:patch (code needs review)» patch (reviewed & tested by the community)

chx's patch was more in line with what we would do. The $status_only flag is just a parameter to ask for the status recorded statically from the beginning of the page request, so no need to go into the other parts of the function, and waste our time there (additionally to causing bugs by opening new output buffers). Arancaytar, thanks for the analysis, but I think chx's patch is better this time.

Committed his patch to 6.x and attaching a combined patch which was rolled against HEAD. This one is to be committed to 7.x.

AttachmentSize
pgsc_HEAD.patch1.82 KB

#29

catch - April 9, 2008 - 13:45

Never got applied to D7 by the looks of things (and still applies).

#30

Drupalr - April 11, 2008 - 21:36

my post below has been fixed. my problem was not related to caching. FYI, it was due to debug output from a hook in using multiping:

http://drupal.org/node/245554

++++++++

Does this problem manifest as messages such as

op=load
op=view
op=alter

appearing in a box (green) above the node??

I'm seeing this in a clean install of 6.2 with caching enabled.

#31

Michelle - April 16, 2008 - 14:21

Any chance of getting this applied to 5.x as well?

Michelle

#32

scriptnews - June 26, 2008 - 20:36

Hi

this issue has not been responded to as far as I could find.

The only fast way to stop this appearing for me was commenting out / hacking the template.

<!--    <?php if ($messages) : print '<div class="messages">' .$messages . '</div>'; endif; ?> -->

Pretty poor solution, but it does the job.

Seems that V6 is just not ready for "simple" public use.

Cheers

Roland

 
 

Drupal is a registered trademark of Dries Buytaert.