Menu
So Ive got a bit of a weird one. I have a debian 9 machine running with Nginx, Varnish, php-fpm and wordpress/woocommerce. The site essentially works, but Im having some weird issues with adding to cart.
The test environment is up at https://awstesting.amr.com.au
Specifically, on the home page there are "add to cart" buttons. On page load you can add 2 different products, but if you try for a 3rd it fails the ajax call with a 502.
this is the general header part when clicking add to cart:
Request URL: https://awstesting.amr.com.au/?wc-ajax=add_to_cart
Request Method: POST
Status Code: 502
Remote Address: 13.236.17.191:443
Referrer Policy: no-referrer-when-downgrade
I will now add my config for Varnish: (Im using Varnish 5.2)
vcl 4.0;
backend default {
.host = "127.0.0.1";
.port = "8080";
.connect_timeout = 600s;
.first_byte_timeout = 600s;
.between_bytes_timeout = 600s;
.max_connections = 800;
}
acl purger {
"localhost";
"127.0.0.1";
}
sub vcl_recv {
# pipe on weird http methods
if (req.method !~ "^GET|HEAD|PUT|POST|TRACE|OPTIONS|DELETE$") {
return(pipe);
}
if (req.method != "GET" && req.method != "HEAD") {
return(pass);
}
if (req.http.X-Requested-With == "XMLHttpRequest"){
return (pass);
}
if (client.ip != "127.0.0.1" && req.http.host ~ "awstesting.amr.com.au") {
set req.http.x-redir = "https://awstesting.amr.com.au" + req.url;
return(synth(850, ""));
}
if (req.method == "PURGE") {
if (!client.ip ~ purger) {
return(synth(405, "This IP is not allowed to send PURGE requests."));
}
return (purge);
}
set req.http.cookie = regsuball(req.http.cookie, "wp-settings-\d+=[^;]+(; )?", "");
set req.http.cookie = regsuball(req.http.cookie, "wp-settings-time-\d+=[^;]+(; )?", "");
# Unset Cookies except for WordPress admin and WooCommerce pages
if (!(req.url ~ "(wp-login|wp-admin|cart|my-account/*|wc-api*|checkout|addons|logout|lost-password|product/*)")) {
unset req.http.cookie;
}
# Pass through the WooCommerce dynamic pages
if (req.url ~ "^/(cart|my-account/*|checkout|wc-api/*|addons|logout|lost-password|product/*)") {
return (pass);
}
# Pass through the WooCommerce add to cart
if (req.url ~ "\?add-to-cart=" ) {
return (pass);
}
# Pass through the WooCommerce API
if (req.url ~ "\?wc-api=" ) {
return (pass);
}
if (req.http.cookie == "") {
unset req.http.cookie;
}
}
sub vcl_synth {
if (resp.status == 850) {
set resp.http.Location = req.http.x-redir;
set resp.status = 302;
return (deliver);
}
}
sub vcl_purge {
set req.method = "GET";
set req.http.X-Purger = "Purged";
return (restart);
}
sub vcl_backend_response {
if (beresp.status >= 300) {
if (beresp.status == 500) {
return (retry);
}
set beresp.uncacheable = true;
set beresp.ttl = 2s;
}
else
{
set beresp.ttl = 24h;
set beresp.grace = 1h;
}
if (bereq.url !~ "wp-admin|wp-login|product|cart|checkout|my-account|/?remove_item=|/?wc-ajax=") {
unset beresp.http.set-cookie;
}
}
sub vcl_deliver {
if (req.http.X-Purger) {
set resp.http.X-Purger = req.http.X-Purger;
}
}
sub vcl_pipe {
return (pipe);
}
sub vcl_pass {
return (fetch);
}
This is my nginx config:
server {
listen 443 ssl spdy http2;
listen [::]:443 ssl spdy http2;
server_name awstesting.amr.com.au;
port_in_redirect off;
server_tokens off;
more_clear_headers Server;
ssl on;
ssl_certificate_key /etc/letsencrypt/keys/0000_key-certbot.pem;
ssl_certificate /etc/letsencrypt/live/awstesting.amr.com.au/fullchain.pem;
ssl_protocols TLSv1 TLSv1.1 TLSv1.2;
ssl_ciphers 'ECDHE-ECDSA-CHACHA20-POLY1305:ECDHE-RSA-CHACHA20-POLY1305:ECDHE-ECDSA-AES128-GCM-SHA256:ECDHE-RSA-AES128-GCM-SHA256:ECDHE-ECDSA-AES256-GCM-SHA384:ECDHE-RSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:ECDHE-ECDSA-AES128-SHA256:ECD$
ssl_prefer_server_ciphers on;
ssl_session_cache shared:SSL:20m;
ssl_session_timeout 60m;
ssl_session_tickets off;
# Diffie-Hellman parameter for DHE ciphersuites, recommended 2048 bits
ssl_dhparam /etc/nginx/ssl/dhparam.pem;
add_header Strict-Transport-Security "max-age=31536000";
add_header X-Content-Type-Options nosniff;
add_header X-Frame-Options "SAMEORIGIN";
add_header X-XSS-Protection "1; mode=block";
# enable ocsp stapling (mechanism by which a site can convey certificate revocation information to visitors in a privacy-preserving, scalable manner)
# http://blog.mozilla.org/security/2013/07/29/ocsp-stapling-in-firefox/
resolver 8.8.8.8 8.8.4.4;
ssl_stapling on;
ssl_stapling_verify on;
ssl_trusted_certificate /etc/letsencrypt/live/awstesting.amr.com.au/fullchain.pem;
location / {
proxy_pass http://127.0.0.1:80;
proxy_http_version 1.1;
proxy_read_timeout 300;
proxy_connect_timeout 300;
proxy_set_header Connection "";
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 X-Forwarded-Proto https;
proxy_set_header HTTPS "on";
access_log /var/www/logs/ssl-access.log;
error_log /var/www/logs/ssl-error.log notice;
}
}
server {
listen 8080;
listen [::]:8080;
server_name awstesting.amr.com.au;
root /var/www/wordpress;
index index.php;
port_in_redirect off;
location / {
try_files $uri $uri/ /index.php?$args;
}
location ~ \.php$ {
try_files $uri $document_root$fastcgi_script_name =404;
fastcgi_split_path_info ^(.+\.php)(/.+)$;
include fastcgi_params;
fastcgi_index index.php;
fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name;
fastcgi_param HTTPS on;
fastcgi_pass unix:/var/run/php/php7.1-fpm.sock;
}
}
This config has the backend http server and the front end proxy https that passes the request to varnish.
Ive tried a few different varnish configurations, but to no avail. So I'm a little lost whats going on. I can clearly see that the server is returning 502, which I suspect means that the http nginx server cant work out who its meant to be adding the product to cart.
Any help would be most appreciated.
Thanks in advance,
Mike
EDIT:
nginx error log:
root@ip-172-31-1-180:/var/log/nginx# tail error.log
2018/06/24 23:19:24 [error] 532#532: *4694 FastCGI sent in stderr: "PHP message: product_type was called incorrectly. Product properties should not be accessed directly. Backtrace: require('wp-blog-header.php'), require_once('wp-includes/template-loader.php'), do_action('template_redirect'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::do_wc_ajax, do_action('wc_ajax_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::add_to_cart, apply_filters('woocommerce_add_to_cart_validation'), WP_Hook->apply_filters, WC_Min_Max_Quantities->add_to_cart, WC_Min_Max_Quantities_Addons->is_composite_product, WC_Abstract_Legacy_Product->__get, wc_doing_it_wrong. This message was added in version 3.0.
PHP message: product_type was called incorrectly. Product properties should not be accessed directly. Backtrace: require('wp-blog-header.php'), require_once('wp-includes/template-loader.php'), do_action('template_redirect'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::do_wc_ajax, do_action('wc_ajax_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::add_to_cart, WC_Cart->add_to_cart, do_action('woocommerce_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_Cart->calculate_totals, do_action('woocommerce_before_calculate_totals'), WP_Hook->do_action, WP_Hook->apply_filters, check_for_starter_pack, WC_Abstract_Legacy_Product->__get, wc_doing_it_wrong. This message was added in version 3.0.
PHP message: The WC_Cart::get_checkout_url function is deprecated since version 2.5. Replace with wc_get_checkout_url" while reading response header from upstream, client: 127.0.0.1, server: awstesting.amr.com.au, request: "POST /?wc-ajax=add_to_cart HTTP/1.1", upstream: "fastcgi://unix:/var/run/php/php7.1-fpm.sock:", host: "awstesting.amr.com.au", referrer: "https://awstesting.amr.com.au/"
2018/06/24 23:19:26 [error] 532#532: *4694 FastCGI sent in stderr: "PHP message: product_type was called incorrectly. Product properties should not be accessed directly. Backtrace: require('wp-blog-header.php'), require_once('wp-includes/template-loader.php'), do_action('template_redirect'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::do_wc_ajax, do_action('wc_ajax_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::add_to_cart, apply_filters('woocommerce_add_to_cart_validation'), WP_Hook->apply_filters, WC_Min_Max_Quantities->add_to_cart, WC_Min_Max_Quantities_Addons->is_composite_product, WC_Abstract_Legacy_Product->__get, wc_doing_it_wrong. This message was added in version 3.0.
PHP message: product_type was called incorrectly. Product properties should not be accessed directly. Backtrace: require('wp-blog-header.php'), require_once('wp-includes/template-loader.php'), do_action('template_redirect'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::do_wc_ajax, do_action('wc_ajax_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::add_to_cart, WC_Cart->add_to_cart, do_action('woocommerce_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_Cart->calculate_totals, do_action('woocommerce_before_calculate_totals'), WP_Hook->do_action, WP_Hook->apply_filters, check_for_starter_pack, WC_Abstract_Legacy_Product->__get, wc_doing_it_wrong. This message was added in version 3.0.
PHP message: product_type was called incorrectly. Product properties should not be accessed directly. Backtrace: require('wp-blog-header.php'), require_once('wp-includes/template-loader.php'), do_action('template_redirect'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::do_wc_ajax, do_action('wc_ajax_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::add_to_cart, WC_Cart->add_to_cart, do_action('woocommerce_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_Cart->calculate_totals, do_action('woocommerce_before_calculate_totals'), WP_Hook->do_action, WP_Hook-
2018/06/24 23:19:27 [error] 532#532: *4694 FastCGI sent in stderr: "PHP message: product_type was called incorrectly. Product properties should not be accessed directly. Backtrace: require('wp-blog-header.php'), require_once('wp-includes/template-loader.php'), do_action('template_redirect'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::do_wc_ajax, do_action('wc_ajax_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::add_to_cart, apply_filters('woocommerce_add_to_cart_validation'), WP_Hook->apply_filters, WC_Min_Max_Quantities->add_to_cart, WC_Min_Max_Quantities_Addons->is_composite_product, WC_Abstract_Legacy_Product->__get, wc_doing_it_wrong. This message was added in version 3.0.
PHP message: product_type was called incorrectly. Product properties should not be accessed directly. Backtrace: require('wp-blog-header.php'), require_once('wp-includes/template-loader.php'), do_action('template_redirect'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::do_wc_ajax, do_action('wc_ajax_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::add_to_cart, WC_Cart->add_to_cart, do_action('woocommerce_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_Cart->calculate_totals, do_action('woocommerce_before_calculate_totals'), WP_Hook->do_action, WP_Hook->apply_filters, check_for_starter_pack, WC_Abstract_Legacy_Product->__get, wc_doing_it_wrong. This message was added in version 3.0.
PHP message: product_type was called incorrectly. Product properties should not be accessed directly. Backtrace: require('wp-blog-header.php'), require_once('wp-includes/template-loader.php'), do_action('template_redirect'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::do_wc_ajax, do_action('wc_ajax_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_AJAX::add_to_cart, WC_Cart->add_to_cart, do_action('woocommerce_add_to_cart'), WP_Hook->do_action, WP_Hook->apply_filters, WC_Cart->calculate_totals, do_action('woocommerce_before_calculate_totals'), WP_Hook->do_action, WP_Hook-
2018/06/24 23:19:27 [error] 532#532: *4694 upstream sent too big header while reading response header from upstream, client: 127.0.0.1, server: awstesting.amr.com.au, request: "POST /?wc-ajax=add_to_cart HTTP/1.1", upstream: "fastcgi://unix:/var/run/php/php7.1-fpm.sock:", host: "awstesting.amr.com.au", referrer: "https://awstesting.amr.com.au/"
Varnish Log:
127.0.0.1 - - [27/Jun/2018:01:38:56 +0000] "POST http://awstesting.amr.com.au/wp-admin/admin-ajax.php HTTP/1.1" 502 575 "https://awstesting.amr.com.au/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36"
127.0.0.1 - - [27/Jun/2018:01:38:58 +0000] "POST http://awstesting.amr.com.au/?wc-ajax=add_to_cart HTTP/1.1" 200 24759 "https://awstesting.amr.com.au/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36"
127.0.0.1 - - [27/Jun/2018:01:39:01 +0000] "POST http://awstesting.amr.com.au/?wc-ajax=add_to_cart HTTP/1.1" 200 29339 "https://awstesting.amr.com.au/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36"
127.0.0.1 - - [27/Jun/2018:01:39:08 +0000] "POST http://awstesting.amr.com.au/?wc-ajax=add_to_cart HTTP/1.1" 200 33927 "https://awstesting.amr.com.au/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36"
127.0.0.1 - - [27/Jun/2018:01:39:10 +0000] "POST http://awstesting.amr.com.au/?wc-ajax=add_to_cart HTTP/1.1" 200 33927 "https://awstesting.amr.com.au/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36"
127.0.0.1 - - [27/Jun/2018:01:39:12 +0000] "POST http://awstesting.amr.com.au/?wc-ajax=add_to_cart HTTP/1.1" 200 33927 "https://awstesting.amr.com.au/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36"
127.0.0.1 - - [27/Jun/2018:01:39:13 +0000] "POST http://awstesting.amr.com.au/?wc-ajax=add_to_cart HTTP/1.1" 200 33927 "https://awstesting.amr.com.au/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36"
127.0.0.1 - - [27/Jun/2018:01:39:18 +0000] "POST http://awstesting.amr.com.au/?wc-ajax=add_to_cart HTTP/1.1" 200 38439 "https://awstesting.amr.com.au/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36"
127.0.0.1 - - [27/Jun/2018:01:39:19 +0000] "POST http://awstesting.amr.com.au/?wc-ajax=add_to_cart HTTP/1.1" 502 575 "https://awstesting.amr.com.au/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36"
EDIT 2:
So the culprit turned out to be Varnish. I bypassed varnish and the site behaved as expected. Im assuming varnish has stricter rules on header sizes and thus dropped connections.
If I eventually work out the issue I will update this post.
949
As these Sites explain
https://www.scalescale.com/tips/nginx/502-bad-gateway-error-using-nginx/
- Nginx with PHP-FPM: same as Apache example, let’s imagine your php daemon stop working, or get’s overloaded by requests, it will not work properly and the all the php requests from nginx would not be served, so, a 502 Bad Gateway error will appear. How to fix it? Restart php-fpm daemon and check the logs.
Understanding this Comment and your Vanish Configurations I could imagine a Scenario where
the Vanish Proxy passes the Ajax Request on to
the Nginx Web Server which itself wants to pass it on to
PHP but which eventually is still busy with the Requests from before processing them in WordPress.
So the Nginx Web Server would report an Error 502 Bad Gateway
I would suggest you to disable the Varnish Cache and try to operate the WordPress Site without it and see if the Error is an Issue of the WordPress Application or the Varnish Cache.
Also display the Processing Time of the Requests in the Logs.
I also observe that the Nginx Logs do not match the Varnish Logs with the Timestamps.
It would be very interesting to see the Nginx Activity log to see which Requests are actually forwarded and which Response they have in the Web Server.
As explained on the Documentation:
https://docs.nginx.com/nginx/admin-guide/monitoring/logging/
160
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With
