Amp-wp: Turn off display_errors during the post-processing phase (sanitization)

[westonruter]

A user reported a two fatal errors showing up in the log:

[28-Feb-2019 17:51:38 UTC] PHP Fatal error:  Allowed memory size of 33554432 bytes exhausted (tried to allocate 72 bytes) in .../wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/Parser.php on line 784
[28-Feb-2019 17:51:38 UTC] PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0

The second error is a symptom of the first (for that see https://github.com/ampproject/amp-wp/issues/1914). The site has display_errors turned on and so the printing of the first error is causing the second error. To prevent the second error from happening, we need to turn off display_errors during post-processing.

This actually identifies an improvement to be made in the plugin: we need to turn off display_errors during post-processing so that this doesn't happen. This should be done in the AMP_Theme_Support::prepare_response() method:

https://github.com/ampproject/amp-wp/blob/616d7a3397b3b3fe3545efbf2559eb21437c5aaa/includes/class-amp-theme-support.php#L1616-L1632

[westonruter]

I was able to reproduce this by forcing my install to have very low memory. I added this to my wp-config.php:

if ( php_sapi_name() !== 'cli' ) {
    define( 'WP_MEMORY_LIMIT', '8M' );
    define( 'WP_MAX_MEMORY_LIMIT', WP_MEMORY_LIMIT );
    ini_set( 'memory_limit', WP_MEMORY_LIMIT );
}

And then I ran:

wp transient delete --all

And then when I tried accessing an AMP page, I got a white screen of death with this in the error log:

[04-Apr-2019 18:26:21 UTC] PHP Fatal error:  Allowed memory size of 8388608 bytes exhausted (tried to allocate 2097160 bytes) in /app/public/content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/Parsing/ParserState.php on line 285
[04-Apr-2019 18:26:21 UTC] PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0

[westonruter]

Note that turning off display_errors in \AMP_Theme_Support::prepare_response() doesn't seem to have any effect on this secondary error. Since this a fatal error anyway, the more important fix is in #1914 to prevent memory from being overrun in the first place.

[aaemnnosttv]

I'm getting the same error without any mention of a memory problem using Amp 1.2.2 (even if it's the only plugin active). Only seems to happen on my local though. Can't reproduce on a real server.

PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0
PHP Stack trace:
PHP   1. shutdown_action_hook() /var/www/html/wp-includes/load.php:0
PHP   2. do_action() /var/www/html/wp-includes/load.php:954
PHP   3. WP_Hook->do_action() /var/www/html/wp-includes/plugin.php:465
PHP   4. WP_Hook->apply_filters() /var/www/html/wp-includes/class-wp-hook.php:310
PHP   5. wp_ob_end_flush_all() /var/www/html/wp-includes/class-wp-hook.php:286
PHP   6. ob_end_flush() /var/www/html/wp-includes/functions.php:4339
PHP   7. AMP_Theme_Support::finish_output_buffering() /var/www/html/wp-includes/functions.php:4339
PHP   8. AMP_Theme_Support::prepare_response() /var/www/html/wp-content/plugins/amp/includes/class-amp-theme-support.php:1768
PHP   9. AMP_Content_Sanitizer::sanitize_document() /var/www/html/wp-content/plugins/amp/includes/class-amp-theme-support.php:2095
PHP  10. AMP_Style_Sanitizer->sanitize() /var/www/html/wp-content/plugins/amp/includes/templates/class-amp-content-sanitizer.php:117
PHP  11. AMP_Style_Sanitizer->process_link_element() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:776
PHP  12. AMP_Style_Sanitizer->process_stylesheet() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:1227
PHP  13. AMP_Style_Sanitizer->prepare_stylesheet() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:1356
PHP  14. Sabberworm\CSS\CSSList\Document->render() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:1631
PHP  15. Sabberworm\CSS\CSSList\Document->render() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/Document.php:106
PHP  16. Sabberworm\CSS\OutputFormat->safely() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/CSSList.php:297
PHP  17. Sabberworm\CSS\OutputFormat->__call() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/CSSList.php:297
PHP  18. call_user_func_array:{/var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121}() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121
PHP  19. Sabberworm\CSS\OutputFormatter->safely() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121
PHP  20. Sabberworm\CSS\CSSList\Document->Sabberworm\CSS\CSSList\{closure}() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:272
PHP  21. Sabberworm\CSS\RuleSet\DeclarationBlock->render() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/CSSList.php:296
PHP  22. Sabberworm\CSS\RuleSet\DeclarationBlock->render() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/RuleSet/DeclarationBlock.php:680
PHP  23. Sabberworm\CSS\OutputFormat->spaceBetweenRules() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/RuleSet/RuleSet.php:177
PHP  24. Sabberworm\CSS\OutputFormat->__call() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/RuleSet/RuleSet.php:177
PHP  25. call_user_func_array:{/var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121}() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121
PHP  26. Sabberworm\CSS\OutputFormatter->spaceBetweenRules() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121
PHP  27. Sabberworm\CSS\OutputFormatter->space() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:224
PHP  28. Sabberworm\CSS\OutputFormatter->prepareSpace() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:208

site-health.txt

[westonruter]

@aaemnnosttv What is your memory limit set to?

[aaemnnosttv]

256M

There's also an attached site-health.txt at the bottom there which should have all the info you need.

[westonruter]

@aaemnnosttv Sure enough. I missed that. Thanks for that helpful info.

Is there any other error occurring in the in the log besides this? I'm confused as to why this is happening. Something similar was raised due to style sanitization in https://github.com/Automattic/jetpack/pull/11318#discussion_r266184878.

Could you try this:

diff --git a/includes/class-amp-theme-support.php b/includes/class-amp-theme-support.php
index 799a6ec4..21994ffb 100644
--- a/includes/class-amp-theme-support.php
+++ b/includes/class-amp-theme-support.php
@@ -2105,7 +2105,7 @@ class AMP_Theme_Support {

        AMP_HTTP::send_server_timing( 'amp_dom_parse', -$dom_parse_start, 'AMP DOM Parse' );

-       $assets = AMP_Content_Sanitizer::sanitize_document( $dom, self::$sanitizer_classes, $args );
+       $assets = @AMP_Content_Sanitizer::sanitize_document( $dom, self::$sanitizer_classes, $args );

        // Determine what the validation errors are.
        $blocking_error_count = 0;

[aaemnnosttv]

I gave that a try but it didn't seem to make a difference it just prevented the error from being logged, but it still died with a 500 (no error was logged in this case).

Here's a fresh one for you, I didn't notice the first one before, but it's still not memory related 😄

PHP Fatal error:  Maximum execution time of 30 seconds exceeded in /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php on line 116
PHP Stack trace:
PHP   1. shutdown_action_hook() /var/www/html/wp-includes/load.php:0
PHP   2. do_action() /var/www/html/wp-includes/load.php:954
PHP   3. WP_Hook->do_action() /var/www/html/wp-includes/plugin.php:465
PHP   4. WP_Hook->apply_filters() /var/www/html/wp-includes/class-wp-hook.php:310
PHP   5. wp_ob_end_flush_all() /var/www/html/wp-includes/class-wp-hook.php:286
PHP   6. ob_end_flush() /var/www/html/wp-includes/functions.php:4339
PHP   7. AMP_Theme_Support::finish_output_buffering() /var/www/html/wp-includes/functions.php:4339
PHP   8. AMP_Theme_Support::prepare_response() /var/www/html/wp-content/plugins/amp/includes/class-amp-theme-support.php:1768
PHP   9. AMP_Content_Sanitizer::sanitize_document() /var/www/html/wp-content/plugins/amp/includes/class-amp-theme-support.php:2095
PHP  10. AMP_Style_Sanitizer->sanitize() /var/www/html/wp-content/plugins/amp/includes/templates/class-amp-content-sanitizer.php:117
PHP  11. AMP_Style_Sanitizer->process_link_element() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:776
PHP  12. AMP_Style_Sanitizer->process_stylesheet() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:1227
PHP  13. AMP_Style_Sanitizer->prepare_stylesheet() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:1356
PHP  14. Sabberworm\CSS\CSSList\Document->render() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:1631
PHP  15. Sabberworm\CSS\CSSList\Document->render() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/Document.php:106
PHP  16. Sabberworm\CSS\OutputFormat->safely() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/CSSList.php:297
PHP  17. Sabberworm\CSS\OutputFormat->__call() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/CSSList.php:297
PHP  18. call_user_func_array:{/var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121}() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121
PHP  19. Sabberworm\CSS\OutputFormatter->safely() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121
PHP  20. Sabberworm\CSS\CSSList\Document->Sabberworm\CSS\CSSList\{closure}() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:272
PHP  21. Sabberworm\CSS\RuleSet\DeclarationBlock->render() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/CSSList.php:296
PHP  22. Sabberworm\CSS\RuleSet\DeclarationBlock->render() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/RuleSet/DeclarationBlock.php:680
PHP  23. Sabberworm\CSS\OutputFormat->spaceBeforeRules() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/RuleSet/RuleSet.php:175
PHP  24. Sabberworm\CSS\OutputFormat->__call() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/RuleSet/RuleSet.php:175
PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0
PHP Stack trace:
PHP   1. shutdown_action_hook() /var/www/html/wp-includes/load.php:0
PHP   2. do_action() /var/www/html/wp-includes/load.php:954
PHP   3. WP_Hook->do_action() /var/www/html/wp-includes/plugin.php:465
PHP   4. WP_Hook->apply_filters() /var/www/html/wp-includes/class-wp-hook.php:310
PHP   5. wp_ob_end_flush_all() /var/www/html/wp-includes/class-wp-hook.php:286
PHP   6. ob_end_flush() /var/www/html/wp-includes/functions.php:4339
PHP   7. AMP_Theme_Support::finish_output_buffering() /var/www/html/wp-includes/functions.php:4339
PHP   8. AMP_Theme_Support::prepare_response() /var/www/html/wp-content/plugins/amp/includes/class-amp-theme-support.php:1768
PHP   9. AMP_Content_Sanitizer::sanitize_document() /var/www/html/wp-content/plugins/amp/includes/class-amp-theme-support.php:2095
PHP  10. AMP_Style_Sanitizer->sanitize() /var/www/html/wp-content/plugins/amp/includes/templates/class-amp-content-sanitizer.php:117
PHP  11. AMP_Style_Sanitizer->process_link_element() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:776
PHP  12. AMP_Style_Sanitizer->process_stylesheet() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:1227
PHP  13. AMP_Style_Sanitizer->prepare_stylesheet() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:1356
PHP  14. Sabberworm\CSS\CSSList\Document->render() /var/www/html/wp-content/plugins/amp/includes/sanitizers/class-amp-style-sanitizer.php:1631
PHP  15. Sabberworm\CSS\CSSList\Document->render() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/Document.php:106
PHP  16. Sabberworm\CSS\OutputFormat->safely() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/CSSList.php:297
PHP  17. Sabberworm\CSS\OutputFormat->__call() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/CSSList.php:297
PHP  18. call_user_func_array:{/var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121}() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121
PHP  19. Sabberworm\CSS\OutputFormatter->safely() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:121
PHP  20. Sabberworm\CSS\CSSList\Document->Sabberworm\CSS\CSSList\{closure}() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/OutputFormat.php:272
PHP  21. Sabberworm\CSS\RuleSet\DeclarationBlock->render() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/CSSList/CSSList.php:296
PHP  22. Sabberworm\CSS\RuleSet\DeclarationBlock->render() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/RuleSet/DeclarationBlock.php:680
PHP  23. Sabberworm\CSS\OutputFormat->spaceBeforeRules() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/RuleSet/RuleSet.php:175
PHP  24. Sabberworm\CSS\OutputFormat->__call() /var/www/html/wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/RuleSet/RuleSet.php:175

I'm using https://github.com/10up/wp-local-docker-v2/ and I just gave it a shot using a fresh environment using these answers (most of them are default) when running 10updocker create and got the same result.

? What is the primary hostname for your site? (Ex: docker.test) amp.test
? Are there additional domains the site should respond to? No
? Do you want to set a proxy for media assets? (i.e. Serving /uploads/ directory assets from a production site) No
? What version of PHP would you like to use? 7.2
? Do you need Elasticsearch No
? Do you want to install WordPress? Yes
? Select a WordPress installation type: Single Site
? Do you want to remove the default content? Yes
? Site Name amp.test
? Admin Username admin
? Admin Password password
? Admin Email [email protected]

I'm guessing you probably don't use this for local development but it should be pretty easy to test. If you want to give it a shot, it's pretty easy. When you're done you'll just want to run 10updocker stop all.

Let me know if there's anything else I can do to help figure this out!

[westonruter]

Ah, ok, that helps. The process is timing out. It should not be taking 30 seconds to generate an AMP response! Two things to try/check:

1. Try increasing the time limit to 60 seconds just to see if it can generate a response.
2. Is your environment able to do loopback requests successfully? I didn't see loopback_requests in your site health output.

I am using Docker, but via Lando: https://github.com/GoogleChromeLabs/wordpressdev/

[aaemnnosttv]

Ok, this is weird.

Bumping it up to 60 _worked_. It did seem to take a little longer but it completed and loaded the amp version. The weird part is that now the amp version seems to load just fine in just a few seconds as I would expect, even for a new post. It seems that there is no caching going on (is there?)
, in my tests on other servers it only takes a few seconds to load the amp version. It seems the problem has been fixed although I don't quite see how 🤔 Is there something special about the first amp render?

I'm testing the plugin in Transitional mode right now (should have mentioned that before). It also seems to fail in standard mode, but it works in Reader.

Is your environment able to do loopback requests successfully?

I noticed a warning about this previously but don't see it on either site at the moment. This came up again though when switching modes on the first site (not the new test that works now)

Transitional mode activated! However, there was an error when checking the AMP validity for your site. cURL error 7: Failed to connect to googlekitlocal.10uplabs.com port 80: Connection refused

[westonruter]

OK, what I suspect is going on here is the CPU is severely throttled in the container, perhaps due to Xdebug being enabled. The CSS parsing is CPU-intensive, so that would explain why the errors seem to always happen during the style sanitizer's execution. Nevertheless, once the CSS has been parsed the result is then stored in a transient to avoid having to re-parse with each request. This is why subsequent requests are being served much faster.

Can you confirm you have Xdebug enabled?

[aaemnnosttv]

Yep, that was it! xdebug was enabled and disabling it fixed the problem 🎉

Perhaps the amp plugin should display a notice if xdebug is enabled?

[westonruter]

@aaemnnosttv Yes, that would be good. Would you like to open a PR? I'm guessing this is important enough to display as a persistent admin notice like we currently do for other such errors, except I don't think having Xdebug enabled should mean the AMP plugin is prevented from initializing. We'll need Xdebug for #1017.

So perhaps something like:

https://github.com/ampproject/amp-wp/blob/217d5929b15bd48e2eaac431d94b03c198ca5466/amp.php#L216-L242

[aaemnnosttv]

@westonruter I've started a simple PR here ☝️ let me know if there's anything else needed 😄

[leecollings]

I don't agree this needs to be a persistent notice. (I don't agree this is an issue at all to be honest) This has never been an issue for me before, and now I'm forced to have an ugly warning message at the top of my admin screens that I have no intention of getting rid of (because I'm not going to disable xdebug on my local and dev machines).

[westonruter]

@leecollings Are you in Transitional or Standard mode? Or are you in Reader mode?

[swissspidy]

For me the notice is shown regardless of the mode I'm using.

A few thoughts:

1. Don't display notice when using Reader mode (at least until #2202 is done)
2. Only display notice when user can manage_options
3. Only display the notice on the AMP plugin settings screen (probably not very effective)
4. Make notice dismissible with persistence in user settings (bonus: still always show it on the settings screen)

[westonruter]

Currently the notice is shown regardless of mode, but the issue with Xdebug may only be noticed in Standard/Transitional modes because the PHP-CSS-Parser is only used in these modes. But eventually in #2202 the Reader mode will use the CSS parser as well (which will enable tree-shaking and minification of CSS per #688).

[leecollings]

https://github.com/ampproject/amp-wp/issues/1915#issuecomment-538143092

No idea. But the fact I don’t have any issue with this plugin, and now I’m forced to see this message, indicates it’s not important enough to warrant a persistent warning message.

I should be able to dismiss this message as I’m not going to disable xdebug, it’s on for a reason and I’m using it.

As I’ve pointed out on the PR that introduced this persistent message, it’s obvious that there’s an issue within your plugin that’s causing the issue. This should be fixed rather than telling the user to change something with their server configuration.

[westonruter]

@leecollings Go to your AMP settings screen in the WP Admin and it will say which mode you are using.

[bobalbert]

We were getting this same error on our site. Turned out to be an issue with a PHP 7.3.9 warning around that function.

PHP Warning: count(): Parameter must be an array or an object that implements Countable in /wp-content/plugins/amp/vendor/sabberworm/php-css-parser/lib/Sabberworm/CSS/Parsing/ParserState.php on line 30

manually fixed the count() by wrapping it to check if is_array().
if( is_array($this->aText) ){
$this->iLength = count($this->aText);
}

now we don't get the memory or buffer errors and pages load. Not sure if this will fix your issue, but it seems to have fixed ours.

[westonruter]

manually fixed the count() by wrapping it to check if is_array().

Submitted fix upstream: https://github.com/sabberworm/PHP-CSS-Parser/pull/171

[swissspidy]

I've created a new issue to discuss the placement of the warning: #3499.