Excessive `X-Cache-Tag` headers causing 502 errors

[khalwat]

@ostark spent a bit of time tracking down an issue for @devinellis and @caseycoates in which if you increased the number of Element queries past a given point, it'd end up causing an immediate 502 error.

"Immediate" is important here, because initially the thought was that it could be timeout related or the like, but it ends up being that the error being thrown was:

2019/06/22 02:29:30 [error] 61#61: *13 upstream sent too big header while reading response header from upstream, client: 172.18.0.1, server: , request: "GET /help/whats-new HTTP/1.1", upstream: "fastcgi://unix:/var/run/php/php7.3-fpm.sock:", host: "localhost:8000"

After a bit of hunting around, it appeared that the Docker container for Nginx and php-fpm were fairly stock default; bumping up the the following as per Nginx-Craft fixed the issue:

        fastcgi_buffer_size 16k;
        fastcgi_buffers 4 16k;

It ends up being that the issue was Upper including an excessive number of X-Cache-Tag headers, to the point where it overflow Nginx's initial buffer for the request from the upstream php-fpm:

X-Cache-Tag: moz-inboel36635 moz-inbose95 moz-inbost18183 moz-inboseomaticGlobals moz-inboel33803 moz-inboel803 moz-inbose17 moz-inboel33223 moz-inboel44423 moz-inbose103 moz-inboel41433 moz-inboel40281 moz-inboel37485 moz-inboel36565 moz-inboel36563 moz-inboel36573 moz-inboel36575 moz-inboel36577 moz-inboel36579 moz-inboel36581 moz-inboel36583 moz-inboel36585 moz-inboel36587 moz-inboel36589 moz-inboel36593 moz-inboel36595 moz-inboel36597 moz-inboel36599 moz-inboel36601 moz-inboel36605 moz-inboel36607 moz-inboel36609 moz-inboel36611 moz-inboel36613 moz-inboel36615 moz-inboel36617 moz-inboel36619 moz-inboel36621 moz-inboel36623 moz-inboel36625 moz-inboel36603 moz-inboel36591 moz-inboel36627 moz-inboel36629 moz-inboel36631 moz-inboel36633 moz-inboel19275 moz-inboel19687 moz-inboel19847 moz-inboel25051 moz-inboel37903 moz-inboel40231 moz-inboel33641 moz-inboel33653 moz-inboel33661 moz-inboel33657 moz-inboel34519 moz-inboel42265 moz-inboel33643 moz-inboel33645 moz-inboel33813 moz-inboel33649 moz-inboel33829 moz-inboel33833 moz-inboel33665 moz-inboel33683 moz-inboel33667 moz-inboel33671 moz-inboel33675 moz-inboel33679 moz-inboel39811 moz-inboel33341 moz-inboel33367 moz-inboel33369 moz-inboel33847 moz-inboel33397 moz-inboel34061 moz-inboel34065 moz-inboel33387 moz-inboel33383 moz-inboel33373 moz-inboel33375 moz-inboel34557 moz-inboel33379 moz-inboel33343 moz-inboel33357 moz-inboel33353 moz-inboel33361 moz-inboel33865 moz-inboel33869 moz-inboel33873 moz-inboel33877 moz-inboel33881 moz-inboel33895 moz-inboel33903 moz-inboel33899 moz-inboel33905 moz-inboel33907 moz-inboel33911 moz-inboel33915 moz-inboel33923 moz-inboel33933 moz-inboel33937 moz-inboel33941 moz-inboel33945 moz-inboel33949 moz-inboel33953 moz-inboel34021 moz-inboel34023 moz-inboel34027 moz-inboel34031 moz-inboel34035 moz-inboel34039 moz-inboel34043 moz-inboel34047 moz-inboel34051 moz-inboel34055 moz-inboel34057 moz-inboel37973 moz-inboel33391 moz-inboel33393 moz-inboel42213 moz-inboel42217 moz-inboel33965 moz-inboel33967 moz-inboel33969 moz-inboel34011 moz-inboel33973 moz-inboel33975 moz-inboel33979 moz-inboel33983 moz-inboel33987 moz-inboel33991 moz-inboel33995 moz-inboel33999 moz-inboel34003 moz-inboel34007 moz-inboel34015 moz-inboel33413 moz-inboel33461 moz-inboel33415 moz-inboel34187 moz-inboel33483 moz-inboel34139 moz-inboel34153 moz-inboel34161 moz-inboel34169 moz-inboel34173 moz-inboel34189 moz-inboel34201 moz-inboel42193 moz-inboel42233 moz-inboel34205 moz-inboel34219 moz-inboel34215 moz-inboel34221 moz-inboel34229 moz-inboel34231 moz-inboel34235 moz-inboel34237 moz-inboel34245 moz-inboel34247 moz-inboel34241 moz-inboel34243 moz-inboel34249 moz-inboel34255 moz-inboel33539 moz-inboel33547 moz-inboel44675 moz-inboel44795 moz-inboel44695 moz-inboel44821 moz-inboel33557 moz-inboel33595 moz-inboel33957 moz-inboel44863 moz-inboel45063 moz-inboel45113 moz-inboel45137 moz-inboel44895 moz-inboel44757 moz-inboel44901 moz-inboel33565 moz-inboel33961 moz-inboel33579 moz-inboel33587 moz-inboel33599 moz-inboel33625 moz-inboel33633 moz-inboel33591 moz-inboel33583 moz-inboel34295 moz-inboel34297 moz-inboel34299 moz-inboel34305 moz-inboel34483 moz-inboel34485 moz-inboel34489 moz-inboel34513 moz-inboel34515 moz-inboel34371 moz-inboel37783 moz-inboel34415 moz-inboel34435 moz-inboel34431 moz-inboel34419 moz-inboel34427 moz-inboel34439 moz-inboel34475 moz-inboel34437 moz-inboel34443 moz-inboel34447 moz-inboel34451 moz-inboel34455 moz-inboel34459 moz-inboel34463 moz-inboel34467 moz-inboel34471 moz-inboel34479 moz-inboel33259 moz-inbose4 moz-inboel33263 moz-inboel33265 moz-inboel33267 moz-inboel41045 moz-inbost9691 moz-inboel41047 moz-inboel41049 moz-inboel41051 moz-inboel41053 moz-inboel41057 moz-inboel41059 moz-inboel41055 moz-inboel41061 moz-inboel10173 moz-inboel10759 moz-inboel11179 moz-inboel10755 moz-inboel19683 moz-inboel36567

(this is a truncated version of the headers)

Given the way upper works with CloudFlare, I'm not sure if you'd consider this to just be "how Upper works" or if there might be some issue that could be address here, so I filed it.

Thoughts?

[ostark]

~I assume the moz-inboelXXXX are the identifiers of the globals. (how Upper works)~

@khalwat Ah, moz-inbo is the prefix. I'd use no or a shorter prefix to reduce the size of the headers. https://github.com/ostark/upper/blob/master/src/config.example.php#L23

[devinellis]

@ostark Ironically, its already being truncated. We were attempting to tag things like this: moz-inbound, moz-inbound-prod, moz-inbound-prod-cms, moz-inbound-prod-cms-${page}. We'd appreciate a way to truncate the header to an arbitrary length, and I bet others might run into this same issue and have a hard time tracking it down so I'd suggest setting a default limit of 16k and mention it in the docs. Let us know how we can help.

We also turned off Craft's cacheElementQueries setting because of performance reasons. However, it seems like Upper is retaining similar behavior (linking entries together somehow). I wonder if it should respect the cacheElementQueries config too?

Thanks for the help

[ostark]

Upper tells the Edge Cache which Elements used/rendered on a page with the Cache Tag header.

@devinellis I assume the issue happens only on pages with many elements.

However, it seems like Upper is retaining similar behavior (linking entries together somehow)

No. At least I'm not aware of :-)

[devinellis]

@ostark yes. I think for the log above, Andrew increased the number of posts shown here in order to reproduce the 502: https://moz.com/help/whats-new.

[khalwat]

Correct @devinellis -- I increased the number of posts shown to 500 -- but even just doubling it caused the issue.

So while I think truncating the prefix is probably a good idea overall, it doesn't solve the problem. It just kicks the can down the road a bit.

You'll still end up at some point with a situation where Nginx will 502 and the cause will be somewhat obfuscated/unexpected.

[timkelty]

Just ran into this as well.

In our case it was running into Varnish's default header limit, which is 4k.

@ostark would you be open to PR that added an option to enforce a limit on the # of tags added?

[ostark]

@timkelty sure! However, the number of tags is not the actual limit, it's the size of the header.

[timkelty]

Right, in which case I think we'd just want to limit it with mb_strcut.

[ostark]

maybe something like this?

$collection->setMaxBytes($this->getSettings()->getMaxBytesForCacheTagHeaders()); // defaults to 3KB

https://github.com/ostark/upper/blob/0518b43dc4b7975adaaf8423aba3d89fa3d6ce45/src/Plugin.php#L96-L99

[ostark]

@timkelty btw, a shorter prefix might help. 4K feels a lot to me ...