Fixed: BootstrapPageCacheTestCase failing in mod_proxy Apache environments

[indigoxela]

Related to #1478.

The test BootstrapPageCacheTestCase fails to 100% on my dev, to 100% in Github Actions, but only randomly with Zen.CI.

Before being able to fix it, I need some explanation for the following part of the existing test:

    $this->backdropGet($test_path, array(), array('If-Modified-Since: ' . $last_modified));
    $this->assertResponse(200, 'Conditional request without If-None-Match returned 200 OK.');
    $this->assertEqual($this->backdropGetHeader('X-Backdrop-Cache'), 'HIT', 'Page was cached.');

I simply don't get that, can anyone explain, please?

$last_modified is the header (datetime) from a previous GET.

Now, on this follow-up request, the header is provided, which I interpret as:

If the resource did not change since last request, please give me a "304", so I know it's still the same, otherwise give me "200".

BUT the expected response in that test is "200" - which would mean it has changed and the browser gets the new version. Huh?
And X-Backdrop-Cache should be a HIT (some more head scratching).

Official info from developer.mozilla.org:

The If-Modified-Since request HTTP header makes the request conditional: the server will send back the requested resource, with a 200 status, only if it has been last modified after the given date. If the resource has not been modified since, the response will be a 304 without any body;

Following that info I interpret this test as wrong by concept, no? Especially when looking at the other asserts in that test. Please enlighten me 😀

---

PR backdrop/backdrop#3665

[indigoxela]

If I put in following code right after the test we're discussing here...

    $foo = $this->backdropGetHeaders(TRUE);
    debug($foo);

The output of $foo is:

array (
  0 => 
  array (
    ':status' => 'HTTP/1.1 304 Not Modified',
    'date' => 'Tue, 13 Jul 2021 08:53:14 GMT',
    'server' => 'Apache/2',
    'etag' => '"1626166391"',
    'expires' => 'Fri, 16 Jan 2015 07:50:00 GMT',
    'cache-control' => 'public, max-age=300',
    'vary' => 'Cookie,Accept-Encoding',
  ),
)

I also played with the sleep() duration before that test block, but that doesn't change anything (more, less, remove...). So, IMO delay can never fix this.

The only thing that fixes that test on my dev is to subtract one second from $last_modified and send that as "If-Modified-Since". But then again I'm not sure if this is what the test should check for.

[quicksketch]

Hi @indigoxela, this took me a while to wrap my head around.

From the looks of things, Backdrop does not respect the If-Modified-Since header unless it is also accompanied by an If-None-Match header. In backdrop_serve_page_from_cache() we see this bit of checking (unmodified since Drupal 7):

  // See if the client has provided the required HTTP headers.
  $if_modified_since = isset($_SERVER['HTTP_IF_MODIFIED_SINCE']) ? strtotime($_SERVER['HTTP_IF_MODIFIED_SINCE']) : FALSE;
  $if_none_match = isset($_SERVER['HTTP_IF_NONE_MATCH']) ? stripslashes($_SERVER['HTTP_IF_NONE_MATCH']) : FALSE;

  if ($if_modified_since && $if_none_match
      && $if_none_match == $etag // etag must match
      && $if_modified_since == $cache->created) {  // if-modified-since must match
    header($_SERVER['SERVER_PROTOCOL'] . ' 304 Not Modified');
    backdrop_send_headers($default_headers);
    return;
  }

So the existing test seems to check that Backdrop behaves as coded, but not actually according to HTTP specification, which should also consider the situation of an If-Modified-Since header alone.

It's possible that what is happening here is that newer versions of Apache (or a proxy in front of Apache) is correctly returning a 304 Not Modified and not even bothering to ask PHP/Backdrop to process the request.

So my interpretation here of how to solve this problem is:

1. Fix backdrop_serve_page_from_cache() to work with an If-Modified-Since header but no If-None-Match header.
2. Fix the test to expect a 304 Response (like you're getting already)

[quicksketch]

I filed a PR at backdrop/backdrop#3665 that correctly implements the HTTP spec, which should make it so that the same response is returned regardless of whether a web server or reverse-proxy returns a 304 Not Modified response, since now Backdrop should behave the same way.

[indigoxela]

So the existing test seems to check that Backdrop behaves as coded, but not actually according to HTTP

@quicksketch many thanks for digging into this!

I've left comments on your PR for further head scratching. 😉

EDIT: Oh, BTW, that sleep(5) before the tests seems unnecessary, or - to make sure all the requests don't happen within the same second - could get reduced to sleep(1). What do you think?

[quicksketch]

could get reduced to sleep(1). What do you think?

Yes, I think this is a situation where we could reduce it down to 1 second. The key thing is that a minimum amount of time passes, since the HTTP headers are to a 1 second of accuracy. I added the delay back in backdrop/backdrop#1367, but I think you're right it doesn't need to be that long.

[indigoxela]

FTR - from our related discussion in our Zulip chat:

I think that mod_proxy is intercepting requests that it thinks should be cached based on the standard behavior... (by @hosef)

Totally makes sense to me. One of the main differences in setup between mod_php and php-fpm is mod_proxy (with proxy_fcgi).
This explains why tests are passing with mod_php but always fail with php-fpm.

[quicksketch]

I updated the PR at backdrop/backdrop#3665 with @hosef and @indigoxela's feedback. Could either of you take another look? Thanks!

[indigoxela]

Tadaaa, tests are passing now with php-fpm (mod_proxy):

Backdrop test run
---------------

Tests to be run:
 - Page cache test (BootstrapPageCacheTestCase)


Test summary
------------

Bootstrap: Page cache test (BootstrapPageCacheTestCase) 152 passes, 0 fails, 0 exceptions, and 40 debug messages.

[quicksketch]

That great! Thanks @indigoxela! I'm feeling good about this PR now, but I think it's confused me so much I'd like another set of eyes to read through it. Anyone up for either testing again or rereading the code for accuracy?

[herbdool]

I think @indigoxela is best positioned to mark this RTBC but I did look at the code and comments and it seems fine now.

[herbdool]

@indigoxela I marked it RTBC based on your review and mine.

[quicksketch]

Thanks folks! I was nervous about merging this for 1.19.3 (the security release) that came out Thursday, but with your approvals and that release out of the way, now is a good time to merge this. I merged backdrop/backdrop#3665 into 1.x and 1.19.x. Thanks!