nginx 502 Bad Gateway, "upstream sent too big header while reading response header from upstream"

[dd32]

I'm encountering the below issue when using Query Monitor on a specific BuddyPress site, the nginx error log contains the following:

[error] 1885#0: *1594 upstream sent too big header while reading response header from upstream,
client: 123.123.123.123,
server: example.org,
request: "POST /profile/edit/group/1/ HTTP/2.0",
upstream: "http://example.org/profile/edit/group/1/",
host: "example.org",
referrer: "https://example.org/profile/edit/group/1/"

In this case, nginx is configured with proxy_buffer_size 4k; (the default) so headers exceeding 4k must be being sent.

I suspect this is the root cause of #293 and #680

[johnbillion]

Yeah there's been several reports of this over the years. Unfortunately there's no way for a PHP script to know the total size of the headers being sent (including cookies) nor for it to know the size limit set by the proxy server.

On a site where a large number of PHP errors are triggered the header size for an Ajax response can exceed 4kb, particularly if many cookies have also accumulated.

One day I'll change this functionality so PHP errors aren't sent directly in the headers.

Suggestions welcome for other improvements but this isn't a priority at the mo.

[dd32]

Yeah I agree and understand, I couldn't see another issue logged that actually had the specific cause, so figured I'd file it at least for reference.

In this case, it's a redirect not a AJAX and it's all the Core deprecation notices. Very confusing and annoying to debug :)

X-QM-overview-time_taken: 0.5830
X-QM-overview-time_usage: 0.6% of 100s limit
X-QM-overview-memory: 7,243 kB
X-QM-overview-memory_usage: 2.8% of 262,144 kB limit
X-QM-php_errors-error-count: 10
X-QM-php_errors-error-1: {"key":"25ccb6c8fd5d722417c3239cc61e7120","type":"deprecated","message":"Return type of Requests_Cookie_Jar::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice","file":....
X-QM-php_errors-error-2: {"key":"62b77d37f6865a26226e66b8d14c38ec","type":"deprecated","message":"Return type of Requests_Cookie_Jar::offsetGet($key) should either be compatible with ArrayAccess::offsetGet(mixed $offset): mixed, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice","file":....
X-QM-php_errors-error-3: {"key":"4741347a403328d3981c6afb9adf4de9","type":"deprecated","message":"Return type of Requests_Cookie_Jar::offsetSet($key, $value) should either be compatible with ArrayAccess::offsetSet(mixed $offset, mixed $value): void, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice","file":....
X-QM-php_errors-error-4: {"key":"966945183c3253ac548cfc10837d52b1","type":"deprecated","message":"Return type of Requests_Cookie_Jar::offsetUnset($key) should either be compatible with ArrayAccess::offsetUnset(mixed $offset): void, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice","file":....
X-QM-php_errors-error-5: {"key":"cd5f35361867569c434f53bbc22ba0f2","type":"deprecated","message":"Return type of Requests_Cookie_Jar::getIterator() should either be compatible with IteratorAggregate::getIterator(): Traversable, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice","file":....
X-QM-php_errors-error-6: {"key":"c23918620a89a5a04900db9825fd22fa","type":"deprecated","message":"Return type of Requests_Utility_CaseInsensitiveDictionary::offsetExists($key) should either be compatible with ArrayAccess::offsetExists(mixed $offset): bool, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice","file":....
X-QM-php_errors-error-7: {"key":"e31ec03c68052174b275f04601bb87b1","type":"deprecated","message":"Return type of Requests_Utility_CaseInsensitiveDictionary::offsetGet($key) should either be compatible with ArrayAccess::offsetGet(mixed $offset): mixed, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice","file":....
X-QM-php_errors-error-8: {"key":"a905431e6053ee08fe4281eb0e8f7a91","type":"deprecated","message":"Return type of Requests_Utility_CaseInsensitiveDictionary::offsetSet($key, $value) should either be compatible with ArrayAccess::offsetSet(mixed $offset, mixed $value): void, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice","file":....
X-QM-php_errors-error-9: {"key":"f6bb14c6d0ce8860f55c505abb09f60b","type":"deprecated","message":"Return type of Requests_Utility_CaseInsensitiveDictionary::offsetUnset($key) should either be compatible with ArrayAccess::offsetUnset(mixed $offset): void, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice","file":....
X-QM-php_errors-error-10: {"key":"12e73f0cc3a5b548f80f1b7f48eaf6a4","type":"deprecated","message":"Return type of Requests_Utility_CaseInsensitiveDictionary::getIterator() should either be compatible with IteratorAggregate::getIterator(): Traversable, or the #[\\ReturnTypeWillChange] attribute should be used to temporarily suppress the notice","file":....
X-QM-redirects-Redirect-Trace: wp_safe_redirect(), bp_core_redirect(), ....

[whysthatso]

@dd32 did you come across a good way to mitigate this? i'm playing around with nginx proxy buffer directives and the buffer sizes, but it's pretty obscure territory. i guess one way would be to just measure sizes of headers and see what makes sense? i followed https://www.getpagespeed.com/server-setup/nginx/tuning-proxy_buffer_size-in-nginx for some guidelines, and that post included some handy curl examples to calculate sizes, but i am not sure how exhaustive this strategy can be in regards to wordpress.

[dd32]

@whysthatso Mitigation for me was to adjust the error reporting to exclude deprecated warnings and notices/warnings being generated. I did just comment out the problematic headers though for a while. I assume there'd be something in the nginx logs for the size of the headers that triggered it, but never checked.

[johnbillion]

I had planned on adding a limit of 10 errors to this header output, but even 10 errors can exceed 4KB.

[rinatkhaziev]

Hey @johnbillion, we're seeing similar issue, in our case it's Varnish but the cause is the same.

It's an awesome feature but lacks a bit both in terms of configurability and safety.

For instance, I as a user of QM, would love to know the message, file and line but I might not need a hundred frame stack trace, and right now I can't do that short of removing the outputter and re-implementing it.

As for the safety, here's quick-and-dirty prototype which can likely be developed in something more robust:

diff --git a/query-monitor/output/headers/php_errors.php b/query-monitor/output/headers/php_errors.php
index 152f59e5c..97a5db6ad 100644
--- a/query-monitor/output/headers/php_errors.php
+++ b/query-monitor/output/headers/php_errors.php
@@ -32,6 +32,10 @@ class QM_Output_Headers_PHP_Errors extends QM_Output_Headers {

        $count = 0;

+       $current_headers_length = strlen( join( "\n", headers_list() ) );
+       // 8192 would be a configurable value
+       $max_qm_headers_length = 8192 - $current_headers_length;
+
        foreach ( $data->errors as $type => $errors ) {

            foreach ( $errors as $error_key => $error ) {
@@ -60,6 +64,10 @@ class QM_Output_Headers_PHP_Errors extends QM_Output_Headers {
            }
        }

+       if ( strlen( join( "\n", $headers ) ) > $max_qm_headers_length ) {
+           // do something to get under the limit
+       }
+
        return array_merge(
            array(
                'error-count' => $count,

[dd32]

I wonder if compressing + base64encoding the data into a single header is a viable option, modern javascript supports https://developer.mozilla.org/en-US/docs/Web/API/CompressionStream which should be able to decode such data.

[rinatkhaziev]

@dd32 I'm not sure there will be a significant gain, if I understood you correctly:

php > var_dump( strlen( join( " ", range( 0, 1024 ) ) ) );
int(4014)
php > var_dump( strlen( base64_encode( gzencode( join( " ", range( 0, 1024 ) ) ) ) ) );
int(2556)

Then, it's likely there will be a single header size limit as well somewhere along the request path. E.g, for Cloudflare total header limit is 32k and single header limit is 16k.

[dd32]

@rinatkhaziev Using range() for that is never going to be very representative for compression, especially when the source contains text and repeated paths/errors.

Going back to the (truncated) above headers in https://github.com/johnbillion/query-monitor/issues/708#issuecomment-1321360887 those just as they are are 3781 chars (longer with full paths), but compressed using your method is 1040 chars.

If the encoded data was split into separate headers at 1kb chunks (which seems like a small limit) most cases that currently trigger this limitation would probably pass through. Some requests would still hit the limits.

These headers exist because there's no other real good way to pass the data back, compressing isn't the perfect solution, but it does reduce the impact.

[johnbillion]

I as a user of QM, would love to know the message, file and line but I might not need a hundred frame stack trace

This is understandable but the problem I repeatedly run into with truncated data is when it truncates something that you need. A complete stack trace can mean the difference between being able to find a root cause and not.

I like the idea of compressing the entire error data then splitting it into smaller headers. 1kb seems fine, we can investigate any browser or proxy limitations and adjust accordingly if necessary.

Todo:

• Gzip (and base64 encode?) the array of errors
• Split the result into 1kb chunks and output a header for each chunk
• Implement JavaScript to decode and uncompress the gzipped data to reconstruct the original array of errors

[GaryJones]

This is understandable but the problem I repeatedly run into with truncated data is when it truncates something that you need. A complete stack trace can mean the difference between being able to find a root cause and not.

How about truncating by default, but making the limit filterable (or making it a boolean filter for any truncation) so that devs can increase the limit to get more of the stack trace if they need it?

[rinatkhaziev]

Using range() for that is never going to be very representative for compression, especially when the source contains text and repeated paths/errors.

Fair point, I was lazy, will try to look up the problematic payload, but it was something very intense, like 30 errors with stack traces from Elementor.

[johnbillion]

Feel free to paste the payload here and we'll see what effect compression has on it

[rinatkhaziev]

This is understandable but the problem I repeatedly run into with truncated data is when it truncates something that you need. A complete stack trace can mean the difference between being able to find a root cause and not.

I definitely see your point, all I'm arguing for is the ability to easily customize the payload. E.g. I want to be able to control whether I send the trace or not, and be able to quickly force the payload size "under control"... somehow :)

The only other counterpoint against compression I see is it's actually going to make it harder to use with tooling like curl, Insomnia, etc, locking users down to browsers.

[Kevin-Hamilton]

It's probably not the easiest path forward since it would require adding persistent storage to QM (which I don't believe it currently has, correct?) ... But my recommendation for this would be to have QM save the information that it is currently sending in the headers, give it a unique key, and then just send a single header with a URL that can be visited to load / display the saved data.

I think there's some security risk, so you'll need to be careful about authentication+authorization, and probably generate URLs with nonces to prevent any CSRF. I would also want to see the feature opt-in through a configuration setting and I would recommend an additional setting that controls how long the persisted data is kept before the plugin auto-deletes it, and maybe an additional button in the settings screen that can sweep the data clean.

[davehayes]

These headers exist because there's no other real good way to pass the data back, compressing isn't the perfect solution, but it does reduce the impact.

The headers are apparently not a good way to pass the data back either. :) Large amounts of errors from (e.g.) trying to upgrade PHP versions can produce surprising results here. This plugin is really useful otherwise.

Given the existence of a database, why not just send a unique key back in the headers and have QM load the information from your own database table? Is there something I am missing?

[rinatkhaziev]

@davehayes the downsides to writing the logs to the database are mostly manifesting when you have a high-traffic website. In that case the size of the db can balloon significantly and the performance of your site will be affected as well, frontend database writes are not something you want either.

Even if your site is not particularly high traffic something like Googlebot might come and instantly turn your day into a bad day.

[johnbillion]

This is certainly something I'm keen to address in Query Monitor but it won't happen for a while yet. Once the client-side rendering work is complete (which is still dragging on in this branch) then it'll be much easier to switch out the current in-memory storage to something more manageable, possible a short-lived transient or something in the object cache. Writing to the filesystem or database on every page load can be problematic on servers with a poor performing filesystem.

[davehayes]

Hm. I' guess I was thinking that putting the plugin on a live site is a fairly uncommon use case, It seems to me you wouldn't necessarily want this plugin on a live high traffic site; it's more for developer types than users right?

In any case, I would love to see an option in the plugin as to where to put "large debug output". For arbitrarily large stack dumps, I personally would never select the "put debug output in headers" option, a local file or the database would be fine for me, or even some hidden div in the page. But this is only my opinion. :)

[crstauf]

you wouldn't necessarily want this plugin on a live high traffic site

QM should only be active for logged-in users (unless it's been overridden), so having active on a live high traffic site shouldn't introduce problems for visitors. In some cases I've limited it to only my user on production sites, so other site admins aren't impacted or distracted.