Quick-Cache only works iff the output buffer contains the entire page #97

mark-kubacki · 2014-04-18T12:49:07Z

Quick-Cache does not take into account that functions registered by ob_start are callbacks which get output in chunks. Quick-Cache works only iff that chunk constitutes an entire page (or output to the client in general). Else, pages get only cached partially or not at all.

Given this minimal example only everything up to and including </head> will be cached:

<?php
ob_start('ob_gzhandler');
ob_start(/* quick-cache */);
// the template starts here:
?>
<html><head>
    <!-- ........ -->
</head><?php ob_flush(); ?>
<body>
    <!-- ........ -->
</body></html>

Indeed, that minimal example is even good practice to decrease time-to-first-byte!

I suggest that Quick-Cache adds checks to [1] to determine in which phase the callback has been called.

Please see PHP's ob_get_status for that: (ob_get_status()['status'] & PHP_OUTPUT_HANDLER_CONT) == PHP_OUTPUT_HANDLER_CONT is true on calls to ob_flush and I expect that when (ob_get_status()['status'] & PHP_OUTPUT_HANDLER_END) == PHP_OUTPUT_HANDLER_END is true you will have everything needed for writing cache files.

Please note that you will need to assemble the page chunk-by-chunk whenever your callback is called.
If there is more than one plugin registering a callback by ob_start Quick-Cache might cache pages which are not completely processed.
ob_get_status does not return everything that is documented:
Some versions of PHP are buggy. Calls to ob_get_status return undocumented values, and sometimes even omit documented ones. For example, PHP 5.5.3 does not return field status at all. Due to a lack of workarounds I suspect that Quick-Cache won't work in with this version of PHP at all.
Behaviour of output buffering functions gets changed between PHP versions. On some you will have to call ob_end_flush yourself.

See also [2] and add_action('wp_head', …) as well as add_action('wp_footer', …).

[1] https://github.com/WebSharks/Quick-Cache/blob/1543fc5efd638b8e9921db9efa14b79a7d9dd036/quick-cache/includes/advanced-cache.tpl.php#L147
[2] https://bugs.php.net/bug.php?id=61272

The text was updated successfully, but these errors were encountered:

raamdev · 2014-04-18T17:11:14Z

@wmark Thank you very much for the bug report. I'm aware that Quick Cache is not compatible with ob_gzhandler(). I've stated elsewhere that Quick Cache is not compatible with output buffers that attempt to pre-compress HTML output.

Your suggestion to add checks "to determine in which phase the callback has been called" would pose, as you mentioned, other problems related to buggy differences in PHP versions with ob_get_status(), of which Quick Cache would need to depend on to work around this issue.

As output buffering is a core part of what Quick Cache does, I'm not sure it makes sense to introduce such potentially buggy behavior into the plugin. I do wish there was a reliable way to make Quick Cache work nicely alongside other plugins that register callbacks with ob_start(), but doing so would mean that we'd need to work around existing PHP bugs and differences between PHP versions.

I'll leave this issue open for now and put some more thought into how I might be able to make this work. I'd also like to get @JasWSInc's thoughts.

jaswrks · 2014-04-18T17:12:19Z

@wmark Thanks for the report!

Output buffers are stackable, so when one is opened and then the buffer is closed, the output callback for the last open handler is called upon; and this does not impact others farther up the chain.

Generally speaking, it's a good practice not to call ob_flush() without having first opened an output buffer yourself (i.e. in your code). Otherwise, as you point out; this can cause problems for other output buffers that may have already been attached; whether they be associated with Quick Cache or another theme/plugin. You are closing something that you did not open.

I do know what you mean about time-to-first-byte though. I have often used flush(); ob_flush(); in order to achieve this myself. However, IMO that does not jive in a WordPress environment; not when we need to leave room for other themes/plugins and maximize compatibility. Calling ob_flush() without having first opened an output buffer, is just asking for a problem.

That said, I'm glad that you posted this issue. I think it's a good idea for us to look at some ways that we can guard against this. I was not aware of it until just now, but it looks like PHP v5.4+ now supports some new options in the third $flags parameter that could help us with this; and there is s back-compatible way to do it in PHP v5.3 too. See: http://www.php.net/manual/en/function.ob-start.php

PHP_OUTPUT_HANDLER_CLEANABLE
PHP_OUTPUT_HANDLER_FLUSHABLE
PHP_OUTPUT_HANDLER_REMOVABLE

As you point out, ob_get_status() could also help us to avoid a conflict. I'm going to take a closer look at what you suggest and do some research on this too. I'll see what we can do to improve!

jaswrks · 2014-04-18T23:39:29Z

@raamdev This test works as expected in PHP v5.3+. I tested up to PHP v5.6-beta1.

<?php
error_reporting(-1);
ini_set('display_errors', TRUE);

ob_implicit_flush();
ob_start('callback_handler', 0, 0);
ob_implicit_flush(TRUE);

function callback_handler($buffer)
    {
        file_put_contents(__DIR__.'/temp.log', $buffer);

        return $buffer;
    }

echo '1,2,3';

ob_flush();

echo ',4,5,6';

ob_flush();

ob_end_clean();

echo ',7,8,9';

/*
 * temp.log contains: 1,2,3,4,5,6,7,8,9
 */

/*
 * Output = 1,2,3,4,5,6,7,8,9
 */

/*
 * Three notices in WP_DEBUG mode were triggered...
 *
 * Notice: ob_flush(): failed to flush buffer of callback_handler (0) in test2.php on line 18
 * Notice: ob_flush(): failed to flush buffer of callback_handler (0) in test2.php on line 22
 * Notice: ob_end_clean(): failed to discard buffer of callback_handler (0) in test2.php on line 24
 */

Needs further testing, but if we can update to something like this it might help us...

Prevent the buffer from being flushed by another theme/plugin.
When/if an out-of-order flush is attempted by another theme/plugin, there will be an E_NOTICE in WP_DEBUG mode to indicate a problem that would assist in troubleshooting an otherwise mysterious/unexplained issue.

Based on Example # 2 here: http://www.php.net/manual/en/function.ob-start.php

ob_start('callback_handler', 0, 0);

jaswrks · 2014-04-19T16:25:15Z

We should also probably consider this WP core routine before making any changes...

/**
 * Flush all output buffers for PHP 5.2.
 *
 * Make sure all output buffers are flushed before our singletons our destroyed.
 *
 * @since 2.2.0
 */
function wp_ob_end_flush_all() {
    $levels = ob_get_level();
    for ($i=0; $i<$levels; $i++)
        ob_end_flush();
}

/**
 * Runs just before PHP shuts down execution.
 *
 * @access private
 * @since 1.2.0
 */
function shutdown_action_hook() {
    /**
     * Fires just before PHP shuts down execution.
     *
     * @since 1.2.0
     */
    do_action( 'shutdown' );
    wp_cache_close();
}

raamdev · 2014-04-21T17:28:53Z

This issue has been closed by wpsharks/comet-cache-pro#17 and this fix, which should greatly improve compatibility with other plugins that use ob_start(), will go out with the next release.

jaswrks · 2014-04-22T23:23:46Z

https://github.com/wmark/CDN-Linker/blob/master/cdn-linker-base.php

NOTE: I reviewed the CDN Linker plugin for any possible conflicts between it's code and QC. It looks solid to me. I'm not seeing any problems with this plugin; but I will try to run some tests against it soon to be sure.

I'm seeing that CDN Linker opens an output buffer on template_redirect; which is after Quick Cache of course. That's fine. Nothing in the code to suggest a problem between QC and CDN Linker at this time.

We had some reports of a white screen when combining these two plugins. Further testing is needed so that we can try to reproduce that issue, but at this time I'm guessing this is probably caused by another theme or plugin in the mix; which might be closing an output buffer out-of-turn.

The latest updates in the QC dev branch should help to detect this being the case. A white screen may still present itself if an output buffer is closed before it should be (in some rare cases), but if WP_DEBUG is enabled it should provide some information about what may have caused the issue; assuming that the latest version of QC is running.

jaswrks · 2014-04-22T23:26:42Z

A white screen could indicate there was an exception thrown by QC. If display_errors is off, it might just present a white screen in this case. The following WP config options should get them to show up.

define('WP_DEBUG', TRUE);
define('WP_DEBUG_DISPLAY', TRUE);

Slobork · 2014-04-24T15:00:36Z

@JasWSInc I'm the one who reported the white screen issue.
Yesterday and today I have tried to get additional information by turning on the debug, as you suggested.

On my Multisite debug shows a couple notices which are caused by Domain Mapping plugin which have already been addressed on the plugin support forum (here and here). So, I applied the fixes and my site doesn't show any errors, warnings or notices while the debug is on.

However, I can only confirm that the white screen will appear only when Quick Cache & CDN-Linker are activated. I'm using the dev version that @raamdev has provided to me a couple of days ago.

Then I have deactivated all other plugins except Quick Cache, CDN-Linker & Domain Mapping. I need the Domain Mapping since it's the MU installation and opposite to the regular WP installations I have this one is still not in the "live stage". However, white screen issue appears even on the regular WP installation (i.e. when the Domain Mapping doesn't exist) so it doesn't seem it's involved in the issue.
Still, even only these 3 plugins are active and WP default theme (TwentyFourteen) the white screen will be caught.

It's interesting that the issue is occasional and it appears only for the Homepage of the TLD.
The problem won't appear if the WordPress is installed in subfolder (tld.com/sub/). Maybe that's the reason you werent able to reproduce it?
Also CDN-Linker must be configured (not just activated) to get into the error. This is because on a page load the CDN-Linker will act as it's not active if you do not set the cdn link.
On the regular WP installations I wanted to bypass deactivating other plugins and going through the same process as with my Multisite since they are live sites. So I installed the WP in a subfolder, that's how I was able to see that with the subfolder installation there won't be problem with a white screen.

Let me know if you have any other suggestion that I could take to get you feedback.

Slobork · 2014-04-24T15:20:20Z

Just to be clear on the above regarding where WP is installed.
It's not about where the WP is installed, it's just important that the issue appears when the TLD is loaded (I can install WP in a subfolder or subdomain, but if I map the domain, the white screen will be cached occasionally as long it's the TLD).

raamdev · 2014-04-24T16:24:18Z

@SBOQ Thank you very much for the additional information!

Just to be clear: You experience the issue only on sub-domain installs?

http://testing.example.com/ would produce the white screen cache while http://example.com/testing/would not? Is that correct?

Also you mentioned that you were able to reproduce this on a non-MU installation, is that correct? If so, where you testing non-MU on a sub-domain installation (e.g., http://testing.example.com/)?

Slobork · 2014-04-24T16:53:42Z

No, I experience the issue no matter where the WP is installed. The problem will appear when the TLD loads. I say "no matter where the WP is installed" since I can have WP in the sub-domain and a mapped domain to be TLD:

If the WP installation is on the http://testing.site.com/ , the problem will still occur on the mapped domain http://site2.com/

http://example.com/ will produce the occasional white screen
http://example.com/testing/ this site will NOT produce the white screen (this is something I have concluded when I installed the non-MU WP in the subdirectory)
http://testing.example.com/ for the site in the sub-domain I'm not sure, but it's something I can pay attention on these days

My non-MU installations are on the TLDs http://example.com/ and the white screen appears occasionally.

raamdev · 2014-04-24T16:58:57Z

My non-MU installations are on the TLDs http://example.com/ and the white screen appears occasionally.

Interesting. I'm going to try to reproduce this in that scenario. Can you tell me what CDN you're using with CDN Linker and any relevant CDN Linker options so that I can attempt to recreate this in an environment that matches yours as closely as possible? If you need to submit anything privately, please use the ticket that you opened earlier.

mark-kubacki · 2014-04-24T17:02:26Z

Well, I don't know what to add to this issue's title. ;-)

Output buffer callbacks get their content chunk-wise. Which is no issue for CDN Linker, no matter what URI you feed it. And, writing files when buffers are about to get flushed is a bad idea, IMHO. I've already made suggestions in my initial comment on how to handle this issue:

Assemble the page from chunks the output buffer callback gets — you seem to have figured out how to limit the amount of calls to one at the expense of flushing (→ using ob_flush() as described on my example; I don't know if this will work with implicit flush or limited buffer sizes, though) — and do any file writing outside that callback.

Slobork · 2014-04-24T17:14:25Z

The image shows the CDN-Linker settings.

jaswrks · 2014-04-25T01:05:23Z

@wmark (cc @raamdev )

@wmark writes...

Output buffer callbacks get their content chunk-wise. Which is no issue for CDN Linker, no matter what URI you feed it. And, writing files when buffers are about to get flushed is a bad idea, IMHO. I've already made suggestions in my initial comment on how to handle this issue:

Assemble the page from chunks the output buffer callback gets — you seem to have figured out how to limit the amount of calls to one at the expense of flushing (→ using ob_flush() as described on my example; I don't know if this will work with implicit flush or limited buffer sizes, though) — and do any file writing outside that callback.

I am researching this issue also. I wanted to touch on this point specifically though. PHP's ob_start() function has a chunked option; but the default behavior associated with an output buffer is not to chunk it. Therefore, unless a developer passes the $chunk_size parameter as a non-zero value to ob_start(), the following behavior is what is documented here. Or, am I missing something? Thanks!

PHP.net says... http://www.php.net/manual/en/function.ob-start.php

If the optional parameter chunk_size is passed, the buffer will be flushed after any output call which causes the buffer's length to equal or exceed chunk_size. The default value 0 means that the output function will only be called when the output buffer is closed.

In my tests this seems to hold true. I have not yet seen a case where $phase indicates a chunk, UNLESS chunks were specifically requested. We are including the following check in our output buffer handler to help catch any edge cases; but this really should not happen, correct?

ob_start('callback_handler', 0, 0);
function callback_handler($buffer, $phase)
{
    if($phase !== (PHP_OUTPUT_HANDLER_START | PHP_OUTPUT_HANDLER_END))
        // Quick Cache does NOT chunk it's output buffering; so this should never happen.
        throw new \exception(sprintf(__('Unexpected OB phase: `%1$s`.', $this->text_domain), $phase));
}

Your last comment seems to suggest that you disagree.
Can you help me understand how chunks may occur even though we're not asking for them? Thanks in advance!

jaswrks · 2014-04-25T03:57:25Z

@raamdev I tested CDN Linker on a non-MU install running the latest dev branch of QC Pro and was unable to reproduce an issue. Running WP v3.9 and QC Pro 000000-dev (latest). Plus CDN Linker: https://github.com/wmark/CDN-Linker

I will try to run some tests against MU w/ domain mapping enabled later.

jaswrks · 2014-04-25T04:15:03Z

@raamdev I tested CDN Linker on an MU install (sub-directories) running the latest dev branch of QC Pro and was unable to reproduce an issue. Running WP v3.9 and QC Pro 000000-dev (latest). Plus CDN Linker: https://github.com/wmark/CDN-Linker

I will run tests with domain mapping enabled next.

jaswrks · 2014-04-25T04:22:07Z

@raamdev @SBOQ I was just able to reproduce an issue on a standard non-MU install; related to the output buffering phase. I have not yet pinpointed the exact underlying cause of this, but it seems this exception is being triggered due to $phase being 11 instead of the expected 9; i.e. it includes the PHP_OUTPUT_HANDLER_CLEAN flag. Not sure how this is even possible yet (given that our output buffer is not cleanable); but I will take a closer look. Could be an issue across different versions of PHP.

ob_start('callback_handler', 0, 0);
function callback_handler($buffer, $phase)
{
    if($phase !== (PHP_OUTPUT_HANDLER_START | PHP_OUTPUT_HANDLER_END))
        // Quick Cache does NOT chunk it's output buffering; so this should never happen.
        throw new \exception(sprintf(__('Unexpected OB phase: `%1$s`.', $this->text_domain), $phase));
}

PHP_OUTPUT_HANDLER_CLEAN available since PHP v5.4.

jaswrks · 2014-04-25T08:20:08Z

@raamdev Regarding my last message...

I cannot find a way to consistently reproduce this issue where the $phase includes the PHP_OUTPUT_HANDLER_CLEAN flag too. It does happen. Tested/confirmed on PHP v5.5.3 running PHP5-FPM and Apache together with WP v3.9 and the latest release of QC Pro. However, it's not a consistent behavior; and I can't reproduce it anywhere from PHP v5.3 - 5.6 outside of a live environment where I noticed this occurring randomly.

Regarding the QC buffer. Since it's now a locked buffer, there is no explicit call to ob_end_clean(), or the like. This means it's up to PHP to close/end the buffer at the end of the request. My best guess at this point, is that PHP5-FPM (or maybe even PHP itself) has a sub-routine that will sometimes end and clean; and other times it will just end it. I haven't found any reports like this, but that seems to be the case.

My suggestion is that we alter this line just a bit to allow for other quirky flags (at least until we can determine what the heck is going on here). I may file a PHP bug report about this also. A locked buffer shouldn't get the _CLEAN flag IMO.

Instead of this...

if($phase !== (PHP_OUTPUT_HANDLER_START | PHP_OUTPUT_HANDLER_END))
    // Quick Cache does NOT chunk it's output buffering; so this should never happen.
    throw new \exception(sprintf(__('Unexpected OB phase: `%1$s`.', $this->text_domain), $phase));

I suggest this...

if(!($phase & PHP_OUTPUT_HANDLER_END)) // We do NOT chunk the buffer; so this should NOT occur.
    throw new \exception(sprintf(__('Unexpected OB phase: `%1$s`.', $this->text_domain), $phase));

Even this check should not be necessary, because the buffer is locked; and it's not chunked. However, I still think it's best to leave it in place to help catch any remaining edge cases that we've not seen yet. At least then we'll know what may have caused the issue.

raamdev · 2014-04-25T17:53:23Z

@JasWSInc Thank you for working on this and for the detailed explanation. I merged your Pull Requests with the changes you suggested.

Slobork mentioned this issue Apr 18, 2014

Incompatibility with CDN Linker plugin (white screen cached) #89

Closed

This was referenced Apr 20, 2014

NC_DEBUG Notices for Quick Cache (and more) wpsharks/comet-cache-pro#16

Merged

Everything, plus Auto Cache Engine wpsharks/comet-cache-pro#17

Merged

raamdev added this to the Next Release milestone Apr 21, 2014

raamdev added enhancement labels Apr 21, 2014

raamdev closed this as completed Apr 21, 2014

raamdev reopened this Apr 24, 2014

jaswrks pushed a commit to wpsharks/comet-cache-pro that referenced this issue Apr 25, 2014

See wpsharks/comet-cache#97 (comment)

f0603a4

jaswrks pushed a commit that referenced this issue Apr 25, 2014

See #97 (comment)

d205219

This was referenced Apr 25, 2014

See https://github.com/WebSharks/Quick-Cache/issues/97#issuecomment-4136... #124

Merged

See https://github.com/WebSharks/Quick-Cache/issues/97#issuecomment-4136... wpsharks/comet-cache-pro#24

Merged

jaswrks pushed a commit to wpsharks/comet-cache-pro that referenced this issue Apr 25, 2014

See wpsharks/comet-cache#97 (comment)

80aecaf

jaswrks pushed a commit that referenced this issue Apr 25, 2014

See #97 (comment)

892ddf7

raamdev closed this as completed Apr 29, 2014

This was referenced May 21, 2014

Google XML Sitemaps Conflict #105

Closed

Investigate Google XML Sitemap Generator plugin compatibility #165

Closed

Locked Output ... Endless Loop #176

Closed

jaswrks mentioned this issue Mar 12, 2015

Random Blank Page #438

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Quick-Cache only works iff the output buffer contains the entire page #97

Quick-Cache only works iff the output buffer contains the entire page #97

mark-kubacki commented Apr 18, 2014

raamdev commented Apr 18, 2014

jaswrks commented Apr 18, 2014

jaswrks commented Apr 18, 2014

jaswrks commented Apr 19, 2014

raamdev commented Apr 21, 2014

jaswrks commented Apr 22, 2014

jaswrks commented Apr 22, 2014

Slobork commented Apr 24, 2014

Slobork commented Apr 24, 2014

raamdev commented Apr 24, 2014

Slobork commented Apr 24, 2014

raamdev commented Apr 24, 2014

mark-kubacki commented Apr 24, 2014

Slobork commented Apr 24, 2014

jaswrks commented Apr 25, 2014

jaswrks commented Apr 25, 2014

jaswrks commented Apr 25, 2014

jaswrks commented Apr 25, 2014

jaswrks commented Apr 25, 2014

raamdev commented Apr 25, 2014

Quick-Cache only works iff the output buffer contains the entire page #97

Quick-Cache only works iff the output buffer contains the entire page #97

Comments

mark-kubacki commented Apr 18, 2014

raamdev commented Apr 18, 2014

jaswrks commented Apr 18, 2014

jaswrks commented Apr 18, 2014

Based on Example # 2 here: http://www.php.net/manual/en/function.ob-start.php

jaswrks commented Apr 19, 2014

raamdev commented Apr 21, 2014

jaswrks commented Apr 22, 2014

jaswrks commented Apr 22, 2014

Slobork commented Apr 24, 2014

Slobork commented Apr 24, 2014

raamdev commented Apr 24, 2014

Slobork commented Apr 24, 2014

raamdev commented Apr 24, 2014

mark-kubacki commented Apr 24, 2014

Slobork commented Apr 24, 2014

jaswrks commented Apr 25, 2014

jaswrks commented Apr 25, 2014

jaswrks commented Apr 25, 2014

jaswrks commented Apr 25, 2014

jaswrks commented Apr 25, 2014

raamdev commented Apr 25, 2014