1337_sanc
Reputation: 159
Varnish+Nginx+Magento cannot serve same page multiple times, resp 502
I have been on the administrative side of a small Magento 2 developers team. They have been setting all their Magento 1 installations behind nginx and php-fpm7.1
I got huge troubles debugging Varnish since it requires a great understanding of header fields and Varnish states.
So they decided to start doing demos with Magento 2 but we noticed that the performance compared to Magento 1 (same stack) is terrible. Nginx could serve 3k requests per second with Magento 1.9.2 and there is a decline to 50 requests per second. Of course Magento 2.2.1 full page cache is not working so they asked of me to setup Varnish, as recommended.
EDIT :
It was about checkout and admin panel only. I was wrong. The problem is not actually only on these places. The problem is everywhere and shows up for almost a second after a succesful request is made. If I load the landing page 5 times in a row only the 1st time will get a 200 and the rest a 502. Also found out that varnishstat gets reset every time i get the 502 error, so i am adding varnishadm panic.show
EDIT 2 :
Problem is not on one request per second. Problem is serving the same Page in one second that leads to this. I can't measure the exact timeframe but it sure happens only when same page is requested in a small timeframe.
Problem still exists on admin panels manual jobs(cache flush, re index etc.).
Problem seems to happen after a page gets cached once and requested back again.After visiting a page and requesting it back even after some seconds (not 1 that I thought, removed previous edit).
Varnishadm panic log shown below (running out of chars)
The Setup:
Nginx serves at ports 80/443 and passes all traffic to Varnish at port 6081(def port).
Varnish works with Magento generated VCL and if needed redirects to Backend at 8080.
The problem: See the edit above.
Typical backend jobs, like cache flush, and www.mymagento.com/Checkout/ lead to 502.
Whenever i try to add something to a cart, and go to checkout i get a 502.
Whenever flush the cache or re-index data i get a 502.
What does nginx report on the time of event?
2017/12/14 16:16:08 [error] 17110#17110: *236271 upstream prematurely closed connection while reading response header from upstream, client: 91.140.10.184, server: dom.com, request: "GET / HTTP/2.0", upstream: "http://127.0.0.1:6081/", host: "dom.com"
2017/12/14 16:16:08 [info] 17110#17110: *236323 recv() failed (104: Connection reset by peer) while sending to client, client: 127.0.0.1, server: dom.com, request: "GET / HTTP/1.0", upstream: "fastcgi://127.0.0.1:9007", host: "dom.com"
2017/12/14 16:16:08 [error] 17110#17110: *236271 connect() failed (111: Connection refused) while connecting to upstream, client: 91.140.10.184, server: dom.com, request: "GET / HTTP/2.0", upstream: "http://127.0.0.1:6081/", host: "dom.com"
2017/12/14 16:16:09 [error] 17110#17110: *236271 upstream prematurely closed connection while reading response header from upstream, client: 91.140.10.184, server: dom.com, request: "GET / HTTP/2.0", upstream: "http://127.0.0.1:6081/", host: "dom.com"
2017/12/14 16:16:09 [info] 17110#17110: *236332 recv() failed (104: Connection reset by peer) while sending to client, client: 127.0.0.1, server: dom.com, request: "GET / HTTP/1.0", upstream: "fastcgi://127.0.0.1:9007", host: "dom.com"
2017/12/14 16:16:09 [error] 17110#17110: *236271 connect() failed (111: Connection refused) while connecting to upstream, client: 91.140.10.184, server: dom.com, request: "GET / HTTP/2.0", upstream: "http://127.0.0.1:6081/", host: "dom.com"
2017/12/14 16:16:09 [error] 17110#17110: *236271 connect() failed (111: Connection refused) while connecting to upstream, client: 91.140.10.184, server: dom.com, request: "GET / HTTP/2.0", upstream: "http://127.0.0.1:6081/", host: "dom.com"
Varnish log
* << BeReq >> 294951
- Begin bereq 294950 pass
- Timestamp Start: 1513009334.530160 0.000000 0.000000
- BereqMethod GET
- BereqURL /checkout/
- BereqProtocol HTTP/1.0
- BereqHeader Host: www.mymagento.com
- BereqHeader X-Forwarded-Host: www.mymagento.com
- BereqHeader X-Real-IP: 37.6.210.242
- BereqHeader X-Forwarded-Proto: https
- BereqHeader X-Forwarded-Port: 443
- BereqHeader X-Forwarded-Proto: https
- BereqHeader Content-Length: 0
- BereqHeader user-agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:57.0) Gecko/20100101 Firefox/57.0
- BereqHeader accept: text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8
- BereqHeader accept-language: en-US,en;q=0.5
- BereqHeader accept-encoding: gzip, deflate, br
- BereqHeader referer: https://www.mymagento.com/catalog/product/view/id/3350/s/1510911799-kalson-elafaki-mayro/category/41/
- BereqHeader upgrade-insecure-requests: 1
- BereqHeader cookie: _ga=GA1.2.2063407653.1510934108; __zlcmid=jpgwnJ1tBFQDKV; intercom-session-xmx5ec9n=dWh5bmg4Y29Sb2FZUW9ybEN6YzJSVGpycE1CZkQvK0hhZnFJYmhNOTJmems0d3p3NkgvSWNORmVVcFRneTVFMy0tOG5JTXJ3aHFYRFlnaTUvbmM4Z1BQZz09--5a2e1ecdcaf4577b3b82a02ad1271c00b50931b1
- BereqHeader X-Forwarded-For: 37.6.210.242, 127.0.0.1
- BereqHeader X-Varnish: 294951
- VCL_call BACKEND_FETCH
- VCL_return fetch
- Backend 14 default default(127.0.0.1,,8080)
- Timestamp Bereq: 1513009334.530267 0.000107 0.000107
- Timestamp Beresp: 1513009334.720461 0.190301 0.190194
- BerespProtocol HTTP/1.1
- BerespStatus 200
- BerespReason OK
- BerespHeader Server: nginx
- BerespHeader Date: Mon, 11 Dec 2017 16:22:14 GMT
- BerespHeader Content-Type: text/html; charset=UTF-8
- BerespHeader Connection: close
- BerespHeader Vary: Accept-Encoding
- BerespHeader X-Powered-By: PHP/7.1
- BerespHeader Set-Cookie: form_key=HitLxJK4OFvkFpFq; expires=Mon, 11-Dec-2017 17:22:14 GMT; Max-Age=3600; path=/; domain=mage2secure.magedeploy.com
- BerespHeader Set-Cookie: form_key=HitLxJK4OFvkFpFq; expires=Mon, 11-Dec-2017 17:22:14 GMT; Max-Age=3600; path=/; domain=mage2secure.magedeploy.com
- BerespHeader Set-Cookie: PHPSESSID=suasda12321sgrb840ebodav186; expires=Mon, 11-Dec-2017 17:22:14 GMT; Max-Age=3600; path=/; domain=www.mymagento.com; secure; HttpOnly
- BerespHeader Set-Cookie: X-Magento-Vary=7f0ec19209469e9c448407b53fa5e756e55a0200; path=/; secure; HttpOnly
- BerespHeader Pragma: no-cache
- BerespHeader Cache-Control: max-age=0, must-revalidate, no-cache, no-store
- BerespHeader Expires: Sun, 11 Dec 2016 16:22:14 GMT
- BerespHeader X-Content-Type-Options: nosniff
- BerespHeader X-XSS-Protection: 1; mode=block
- BerespHeader X-Frame-Options: SAMEORIGIN
- TTL RFC 0 -1 -1 1513009335 1513009335 1513009334 1481473334 0
- VCL_call BACKEND_RESPONSE
- TTL VCL -1 259200 0 1513009335
- TTL VCL 120 259200 0 1513009335
- VCL_return deliver
- BerespHeader Content-Encoding: gzip
- Storage malloc Transient
- ObjProtocol HTTP/1.1
- ObjStatus 200
- ObjReason OK
- ObjHeader Server: nginx
- ObjHeader Date: Mon, 11 Dec 2017 16:22:14 GMT
- ObjHeader Content-Type: text/html; charset=UTF-8
- ObjHeader Vary: Accept-Encoding
- ObjHeader X-Powered-By: PHP/7.0.26
- ObjHeader Set-Cookie: form_key=HitLxJK4OFvkFpFq; expires=Mon, 11-Dec-2017 17:22:14 GMT; Max-Age=3600; path=/; domain=mage2secure.magedeploy.com
- ObjHeader Set-Cookie: form_key=HitLxJK4OFvkFpFq; expires=Mon, 11-Dec-2017 17:22:14 GMT; Max-Age=3600; path=/; domain=mage2secure.magedeploy.com
- ObjHeader Set-Cookie: PHPSESSID=su53asdad223sgrb83dav186; expires=Mon, 11-Dec-2017 17:22:14 GMT; Max-Age=3600; path=/; domain=mage2secure.magedeploy.com; secure; HttpOnly
- ObjHeader Set-Cookie: X-Magento-Vary=7f0ec19209469e9c448407b53fa5e756e55a0200; path=/; secure; HttpOnly
- ObjHeader Pragma: no-cache
- ObjHeader Cache-Control: max-age=0, must-revalidate, no-cache, no-store
- ObjHeader Expires: Sun, 11 Dec 2016 16:22:14 GMT
- ObjHeader X-Content-Type-Options: nosniff
- ObjHeader X-XSS-Protection: 1; mode=block
- ObjHeader X-Frame-Options: SAMEORIGIN
- ObjHeader Content-Encoding: gzip
- Fetch_Body 4 eof -
- VSL flush
- End synth
Varnish VCL
vcl 4.0; import std;
# The minimal Varnish version is 4.0 For SSL offloading, pass the following header in your proxy server or load balancer: 'X-Forwarded-Proto:
# https'
backend default {
.host = "localhost";
.port = "8080";
.first_byte_timeout = 900s;
.probe = {
.url = "/health_check.php";
.timeout = 2s;
.interval = 5s;
.window = 10;
.threshold = 5;
}
}
acl purge {
"localhost";
}
sub vcl_recv {
if (req.method == "PURGE") {
if (client.ip !~ purge) {
return (synth(405, "Method not allowed"));
}
# To use the X-Pool header for purging varnish during automated deployments, make sure the X-Pool header has been added to the response in
# your backend server config. This is used, for example, by the capistrano-magento2 gem for purging old content from varnish during it's
# deploy routine.
if (!req.http.X-Magento-Tags-Pattern && !req.http.X-Pool) {
return (synth(400, "X-Magento-Tags-Pattern or X-Pool header required"));
}
if (req.http.X-Magento-Tags-Pattern) {
ban("obj.http.X-Magento-Tags ~ " + req.http.X-Magento-Tags-Pattern);
}
if (req.http.X-Pool) {
ban("obj.http.X-Pool ~ " + req.http.X-Pool);
}
return (synth(200, "Purged"));
}
if (req.method != "GET" &&
req.method != "HEAD" &&
req.method != "PUT" &&
req.method != "POST" &&
req.method != "TRACE" &&
req.method != "OPTIONS" &&
req.method != "DELETE") {
/* Non-RFC2616 or CONNECT which is weird. */
#was pi pe
return (pass);
}
# We only deal with GET and HEAD by default
if (req.method != "GET" && req.method != "HEAD") {
return (pass);
}
# Bypass shopping cart, checkout and search requests
if (req.url ~ "/checkout" || req.url ~ "/catalogsearch") {
return (pass);
}
# Bypass health check requests
if (req.url ~ "/health_check.php") {
return (pass);
}
# Set initial grace period usage status
set req.http.grace = "none";
# normalize url in case of leading HTTP scheme and domain
set req.url = regsub(req.url, "^http[s]?://", "");
# collect all cookies
std.collect(req.http.Cookie);
# Compression filter. See https://www.varnish-cache.org/trac/wiki/FAQ/Compression
if (req.http.Accept-Encoding) {
if (req.url ~ "\.(jpg|jpeg|png|gif|gz|tgz|bz2|tbz|mp3|ogg|swf|flv)$") {
# No point in compressing these
unset req.http.Accept-Encoding;
} elsif (req.http.Accept-Encoding ~ "gzip") {
set req.http.Accept-Encoding = "gzip";
} elsif (req.http.Accept-Encoding ~ "deflate" && req.http.user-agent !~ "MSIE") {
set req.http.Accept-Encoding = "deflate";
} else {
# unkown algorithm
unset req.http.Accept-Encoding;
}
}
# Remove Google gclid parameters to minimize the cache objects
set req.url = regsuball(req.url,"\?gclid=[^&]+$",""); # strips when QS = "?gclid=AAA"
set req.url = regsuball(req.url,"\?gclid=[^&]+&","?"); # strips when QS = "?gclid=AAA&foo=bar"
set req.url = regsuball(req.url,"&gclid=[^&]+",""); # strips when QS = "?foo=bar&gclid=AAA" or QS = "?foo=bar&gclid=AAA&bar=baz"
# Static files caching
if (req.url ~ "^/(pub/)?(media|static)/") {
# Static files should not be cached by default
# return (hash);
# But if you use a few locales and don't use CDN you can enable caching static files by commenting previous line (#return (pass);) and
#uncommenting next 3 lines
unset req.http.Https;
unset req.http.X-Forwarded-Proto;
unset req.http.Cookie;
}
return (hash);
}
sub vcl_hash {
if (req.http.cookie ~ "X-Magento-Vary=") {
hash_data(regsub(req.http.cookie, "^.*?X-Magento-Vary=([^;]+);*.*$", "\1"));
}
# For multi site configurations to not cache each other's content
if (req.http.host) {
hash_data(req.http.host);
} else {
hash_data(server.ip);
}
# To make sure http users don't see ssl warning
if (req.http.X-Forwarded-Proto) {
hash_data(req.http.X-Forwarded-Proto);
}
if (req.http.user-agent ~ "(?i)iPhone") {
hash_data("8");
} elsif (req.http.user-agent ~ "(?i)iPod") {
hash_data("8");
} elsif (req.http.user-agent ~ "(?i)BlackBerry") {
hash_data("8");
} elsif (req.http.user-agent ~ "(?i)Palm") {
hash_data("8");
} elsif (req.http.user-agent ~ "(?i)Googlebot\-Mobile") {
hash_data("8");
} elsif (req.http.user-agent ~ "(?i)Windows Mobile") {
hash_data("8");
} elsif (req.http.user-agent ~ "(?i)Android") {
hash_data("8");
} elsif (req.http.user-agent ~ "(?i)Opera") {
hash_data("8");
}
}
sub vcl_backend_response {
set beresp.grace = 3d;
if (beresp.http.content-type ~ "text") {
set beresp.do_esi = true;
}
if (bereq.url ~ "\.js$" || beresp.http.content-type ~ "text") {
set beresp.do_gzip = true;
}
# cache only successfully responses and 404s
if (beresp.status != 200 && beresp.status != 404) {
set beresp.ttl = 0s;
set beresp.uncacheable = true;
return (deliver);
} elsif (beresp.http.Cache-Control ~ "private") {
set beresp.uncacheable = true;
set beresp.ttl = 86400s;
return (deliver);
}
if (beresp.http.X-Magento-Debug) {
set beresp.http.X-Magento-Cache-Control = beresp.http.Cache-Control;
}
# validate if we need to cache it and prevent from setting cookie
if (beresp.ttl > 0s && (bereq.method == "GET" || bereq.method == "HEAD")) {
unset beresp.http.set-cookie;
}
# If page is not cacheable then bypass varnish for 2 minutes as Hit-For-Pass
if (beresp.ttl <= 0s ||
beresp.http.Surrogate-control ~ "no-store" ||
(!beresp.http.Surrogate-Control && beresp.http.Vary == "*")) {
# Mark as Hit-For-Pass for the next 2 minutes
set beresp.ttl = 120s;
set beresp.uncacheable = true;
}
return (deliver);
}
sub vcl_deliver {
if (resp.http.X-Magento-Debug) {
if (resp.http.x-varnish ~ " ") {
set resp.http.X-Magento-Cache-Debug = "HIT";
set resp.http.Grace = req.http.grace;
} else {
set resp.http.X-Magento-Cache-Debug = "MISS";
}
} else {
unset resp.http.Age;
}
unset resp.http.X-Magento-Debug;
unset resp.http.X-Magento-Tags;
unset resp.http.X-Powered-By;
unset resp.http.Server;
unset resp.http.X-Varnish;
unset resp.http.Via;
unset resp.http.Link;
}
sub vcl_hit {
if (obj.ttl >= 0s) {
# Hit within TTL period
return (deliver);
}
if (std.healthy(req.backend_hint)) {
if (obj.ttl + 300s > 0s) {
# Hit after TTL expiration, but within grace period
set req.http.grace = "normal (healthy server)";
return (deliver);
} else {
# Hit after TTL and grace expiration
return (fetch);
}
} else {
# server is not healthy, retrieve from cache
set req.http.grace = "unlimited (unhealthy server)";
return (deliver);
}
}
Nginx Site Config
server {
listen 80;
server_name www.mymagento.com;
location /.well-known/ {
default_type "text/plain";
try_files $uri =404;
}
return 301 https://$host$request_uri;
}
server {
server_name www.mymagento.com;
listen 443 ssl http2;
ssl_certificate /etc/letsencrypt/live/magento/fullchain.pem;
ssl_certificate_key /etc/letsencrypt/live/magento/privkey.pem;
# port_in_redirect off;
include https_basic.conf;
keepalive_timeout 0s;
location / {
proxy_pass http://127.0.0.1:6081;
proxy_set_header Host $http_host;
proxy_set_header X-Forwarded-Host $http_host;
proxy_set_header X-Real-IP $remote_addr;
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
# proxy_set_header Ssl-Offloaded "1";
proxy_set_header X-Forwarded-Proto https;
proxy_set_header X-Forwarded-Port 443;
proxy_set_header X-Forwarded-Proto $scheme;
}
}
server {
server_name www.mymagento.com;
listen 8080;
root /home/magento/public_html/pub/;
set $HTTPS_FORWARD on;
index index.php;
charset UTF-8;
error_page 404 403 = /errors/404.php;
expires off;
# PHP entry point for setup application
location ~* ^/setup($|/) {
root /home/kirakalo/public_html/;
location ~ ^/setup/index.php {
# if (!-e $request_filename) { rewrite / /index.php last; }
fastcgi_pass 127.0.0.1:9007;
fastcgi_index index.php;
fastcgi_read_timeout 600s;
fastcgi_connect_timeout 600s;
fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name;
# fastcgi_param PATH_TRANSLATED $document_root$fastcgi_script_name;
include fastcgi_params;
# access_log /var/log/nginx/phpfpmonly-access.log;
}
location ~ ^/setup/(?!pub/). {
deny all;
}
location ~ ^/setup/pub/ {
add_header X-Frame-Options "SAMEORIGIN";
}
}
# PHP entry point for update application
location ~* ^/update($|/) {
root /home/kirakalo/public_html/;
location ~ ^/update/index.php {
fastcgi_split_path_info ^(/update/index.php)(/.+)$;
fastcgi_pass 127.0.0.1:9007;
fastcgi_index index.php;
fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name;
fastcgi_param PATH_INFO $fastcgi_path_info;
# fastcgi_param PATH_TRANSLATED $document_root$fastcgi_script_name;
include fastcgi_params;
# access_log /var/log/nginx/phpfpmonly-access.log;
}
# Deny everything but index.php
location ~ ^/update/(?!pub/). {
deny all;
}
location ~ ^/update/pub/ {
add_header X-Frame-Options "SAMEORIGIN";
}
}
location / {
try_files $uri $uri/ /index.php$is_args$args;
}
location /pub/ {
location ~ ^/pub/media/(downloadable|customer|import|theme_customization/.*.xml) {
deny all;
}
alias /home/kirakalo/public_html/pub/;
add_header X-Frame-Options "SAMEORIGIN";
location ~ ^/pub/static/version {
rewrite ^/pub/static/(version\d*/)?(.*)$ /pub/static/$2 last;
}
}
location /static/ {
# Uncomment the following line in production mode
# expires max;
# Remove signature of the static files that is used to overcome the browser cache
location ~ ^/static/version {
rewrite ^/static/(version\d*/)?(.*)$ /static/$2 last;
}
location ~* .(ico|jpg|jpeg|png|gif|svg|js|css|swf|eot|ttf|otf|woff|woff2)$ {
add_header Cache-Control "public";
add_header X-Frame-Options "SAMEORIGIN";
expires +1y;
if (!-f $request_filename) {
rewrite ^/static/?(.*)$ /static.php?resource=$1 last;
}
}
location ~* .(zip|gz|gzip|bz2|csv|xml)$ {
add_header Cache-Control "no-store";
add_header X-Frame-Options "SAMEORIGIN";
expires off;
if (!-f $request_filename) {
rewrite ^/static/?(.*)$ /static.php?resource=$1 last;
}
}
if (!-f $request_filename) {
rewrite ^/static/?(.*)$ /static.php?resource=$1 last;
}
add_header X-Frame-Options "SAMEORIGIN";
}
location /media/ {
try_files $uri $uri/ /get.php$is_args$args;
location ~ ^/media/theme_customization/.*.xml {
deny all;
}
location ~* .(ico|jpg|jpeg|png|gif|svg|js|css|swf|eot|ttf|otf|woff|woff2)$ {
add_header Cache-Control "public";
add_header X-Frame-Options "SAMEORIGIN";
# expires +1y;
try_files $uri $uri/ /get.php$is_args$args;
}
location ~* .(zip|gz|gzip|bz2|csv|xml)$ {
add_header Cache-Control "no-store";
add_header X-Frame-Options "SAMEORIGIN";
expires off;
try_files $uri $uri/ /get.php$is_args$args;
}
add_header X-Frame-Options "SAMEORIGIN";
}
location /media/customer/ {
deny all;
}
location /media/downloadable/ {
deny all;
}
location /media/import/ {
deny all;
}
location ~ (health_check|op1337|index|get|static|report|404|503).php$ {
try_files $uri =404;
fastcgi_pass 127.0.0.1:9007;
fastcgi_param HTTPS $HTTPS_FORWARD;
# fastcgi_read_timeout 600s;
# fastcgi_connect_timeout 600s;
fastcgi_index index.php;
fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name;
fastcgi_param PATH_INFO $fastcgi_path_info;
include fastcgi_params;
access_log /var/log/nginx/phpfpmonly-access.log;
}
location ~* (.php$|.htaccess$|.git) {
deny all;
}
}
Where is the problem hiding ?Is this bad config or maybe related to the teams code? I am completely new to Varnish and trying to figure this out has become a complete headache.
Edit: Noticed that when I log in as a user to the page the cart is filled even if I login/logout. Note that There is a page that you get to see your cart items. This pages response seems to be "Your cart is empty" even if there is a box on the top that shows items-to-buy and quantities/price.
Note : This problem only exists after varnish came in the picture. As I said already server could handle only up to ~100 requests per second with Magento 2 which is an actually terrible number.
Upvotes: 3
Views: 2178
Answers (1)
1337_sanc
Reputation: 159
I ended up reaching the #varnish channel on IRC and asking for help. So Guillaume Quintard pointed out the error.
If we inspect the panic.show log on line 8 of pastebin we can see the overflow keyword.
ws = 0x7f285f09f0e0 { OVERFLOW
The rest of the message refers to the backend's response. So in the end what it means is the headers of the backend's reply were bigger than varnish could handle.
Solution : Increase the parameter workspace_backend. He suggested I double it up.
By running varnishadm param.show you can trace the value assigned and try to double it up. I went from 64k to 128k.
To assign the new value add to your varnish.params file, on the DAEMON OPTS context the parameter and value like :
-p workspace_backend=n
where n->bytes.
Kudos to you dear Guillaume and varnish-software team for the assistance.
Upvotes: 2
Related Questions
- Varnish 503 Backend Fetch failed
- Varnish not Caching Requests
- varnish Error 503 Backend fetch failed only on web app delivered via nginx (varnishlog attached)
- Why Varnish stops caching 200 response after 500 error
- Varnish isnt caching with pagespeed
- Varnish CentOS - Error 503 Backend fetch failed
- Varnish Cache - Connection Refused
- Nginx & Varnish connection error
- Varnish say backend busy conn too many
- Varnish 3.0 returns 503 error