upstream sent too big header while reading response header from upstream, client (nginx, varnish)

Question

I have been consistently getting a "upstream sent too big header while reading response header from upstream" error in my nginx log.

To start with, this is the architecture I have:

This error is logged by the nginx server running on port 8080.

2018/07/06 11:17:29 [error] 18857#18857: *39687 upstream sent too big header while reading response header from upstream, client: 127.0.0.1, server: amr.com.au, request: "POST /wp-admin/admin-ajax.php HTTP/1.1", upstream: "fastcgi://unix:/var/run/php/php7.1-fpm.sock:", host: "amr.com.au", referrer: "https://amr.com.au/wp-admin/"

i have tried this Upstream too big - nginx + codeigniter but to no avail.

I will put my php, nginx and varnish config here for reference.

varnish:

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 {


    # Forward client's IP to the backend
    if (req.restarts == 0) {
        if (req.http.X-Real-IP) {
            set req.http.X-Forwarded-For = req.http.X-Real-IP;
        } else if (req.http.X-Forwarded-For) {
            set req.http.X-Forwarded-For = req.http.X-Forwarded-For + ", " + client.ip;
        } else {
            set req.http.X-Forwarded-For = client.ip;
        }
    }

    # 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 ~ "amr.com.au") {
            set req.http.x-redir = "https://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);
    }

    # 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);
    }


}

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);
}

nginx.conf

user admin;
worker_processes auto;
pid /run/nginx.pid;
include /etc/nginx/modules-enabled/*.conf;

worker_rlimit_nofile 50000;


events {
        use epoll;
    worker_connections 100000;
    multi_accept on;
}

http {

    ##
    # Basic Settings
    ##

    sendfile on;
    tcp_nopush on;
    tcp_nodelay on;
    keepalive_timeout 65s;

reset_timedout_connection on;


    types_hash_max_size 2048;
    server_tokens off;

    include /etc/nginx/mime.types;
    default_type application/octet-stream;


    ##
    # Gzip Settings
    ##

    gzip on;
        gzip_min_length 1000;
        gzip_types text/plain text/css application/json application/x-javascript text/xml application/xml application/xml+rss text/javascript;

    gzip_disable "msie6";


    open_file_cache max=50000 inactive=20s;
    open_file_cache_valid 30s;
    open_file_cache_min_uses 2;

    client_max_body_size 512m;

proxy_buffer_size   128k;
proxy_buffers   4 256k;
proxy_busy_buffers_size   256k;


    include /etc/nginx/conf.d/*.conf;
    include /etc/nginx/sites-enabled/*;
}

nginx sites avaliable

server {
   listen  443 ssl http2;
   listen  [::]:443 ssl http2;
   server_name  amr.com.au;
   port_in_redirect off;
   server_tokens off;
   more_clear_headers Server;

   ssl on;
   ssl_certificate_key /etc/letsencrypt/keys/0001_key-certbot.pem;
   ssl_certificate /etc/letsencrypt/live/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:ECDHE-RSA-AES128-SHA256:ECDHE-ECDSA-AES128-SHA:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA:ECDHE-ECDSA-AES256-SHA384:ECDHE-ECDSA-AES256-SHA:ECDHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA256:DHE-RSA-AES128-SHA:DHE-RSA-AES256-SHA256:DHE-RSA-AES256-SHA:ECDHE-ECDSA-DES-CBC3-SHA:ECDHE-RSA-DES-CBC3-SHA:EDH-RSA-DES-CBC3-SHA:AES128-GCM-SHA256:AES256-GCM-SHA384:AES128-SHA256:AES256-SHA256:AES128-SHA:AES256-SHA:DES-CBC3-SHA:!DSS';
   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/amr.com.au/fullchain.pem;


   location = /favicon.ico {
     log_not_found off;
     access_log off;
   }

   location = /robots.txt {
     allow all;
     log_not_found off;
     access_log off;
   }


   location / {
     proxy_pass http://127.0.0.1:80;
     proxy_http_version 1.1;

#     proxy_connect_timeout       300s;
#     proxy_send_timeout          300s;
#     proxy_read_timeout          300s;
#     send_timeout                300s;

#     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";




  # time out settings
  proxy_connect_timeout 159s;
  proxy_send_timeout   600s;
  proxy_read_timeout   600s;

#  proxy_buffer_size    256k;
#  proxy_buffers     32 256k;
#  proxy_busy_buffers_size 256k;
#  proxy_temp_file_write_size 256k;

  proxy_pass_header Set-Cookie;
  proxy_redirect     off;
  proxy_hide_header  Vary;
  proxy_set_header   Accept-Encoding '';
  proxy_ignore_headers Cache-Control Expires;
  proxy_set_header   Referer $http_referer;
  proxy_set_header   Host   $host;
  proxy_set_header   Cookie $http_cookie;
  proxy_set_header   X-Real-IP  $remote_addr;
  proxy_set_header X-Forwarded-Host $host;
  proxy_set_header X-Forwarded-Server $host;
  proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;






     access_log /var/www/logs/ssl-access.log;
     error_log  /var/www/logs/ssl-error.log error;

     }
}

server {
   listen 8080;
   listen [::]:8080;
   server_name amr.com.au;
   root /var/www/amr-prod;
   index index.php;
   port_in_redirect off;


    client_header_buffer_size 2M;
    large_client_header_buffers 16 2M;

client_body_buffer_size 100M;
client_max_body_size 100M;
fastcgi_buffers 256 200k;



     access_log /var/www/logs/backend-access.log;
     error_log  /var/www/logs/backend-error.log warn;


   rewrite ^/sitemap(-+([a-zA-Z0-9_-]+))?\.xml$ "/index.php?xml_sitemap=params=$2" last;
   rewrite ^/sitemap(-+([a-zA-Z0-9_-]+))?\.xml\.gz$ "/index.php?xml_sitemap=params=$2;zip=true" last;
   rewrite ^/sitemap(-+([a-zA-Z0-9_-]+))?\.html$ "/index.php?xml_sitemap=params=$2;html=true" last;
   rewrite ^/sitemap(-+([a-zA-Z0-9_-]+))?\.html.gz$ "/index.php?xml_sitemap=params=$2;html=true;zip=true" last;

   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;

fastcgi_buffer_size 128k;
fastcgi_buffers 4 256k;
fastcgi_busy_buffers_size 256k;

       fastcgi_read_timeout 240s;

       }
}

also for reference:

awk '($9 ~ /200/) { i++;sum+=$10;max=$10>max?$10:max; } END { printf("Maximum: %d\nAverage: %d\n",max,i?sum/i:0); }' access.log

Maximum: 62833994 Average: 68531

Can someone help me work out why im getting that error? It doesnt seem to make any sense to me?? It looks like I have the configuration correct.

Thanks in advance,

Mike

EDIT:

So, I made a replica server, and turned off Varnish, and hey presto, it works.. So theres something going on in Varnish. I havent had time to investigate it yet, but I will try to this week and update if I can work it out.

Have you fixed all the errors your Wordpress install is kicking out yet? Your PHP log is going to be by far the most informative for you. Are all your plugins PHP 7.1 friendly? I told you last week why you get that error, PHP is outputting so much to STDERR that Nginx header buffers are overflowing and causing it to return 502. Fix your Wordpress and you'll fix your problem. — miknik, Jul 06 '18 at 23:35

Chris Slothouber · Answer 1 · 2018-07-06T14:40:13.033

1

Have you combed through your PHP error logs around the same time as the nginx error? The nginx error upstream sent too big header while reading response header from upstream is a pretty generic message, and could be related to any number of things going wrong. A likely culprit is a buggy PHP script. Other possibilities include a thread crash, or any other number header problems.

Check out answer 33878041 for some additional points to investigate when debugging this upstream error. This includes verifying that Content-Length does not exceed the actual content length of the POST transaction.

edited Jul 06 '18 at 14:40

answered Jul 06 '18 at 04:24

Chris Slothouber

115
9

I have.. there are no errors logged by php anywhere near the time it happens. – Mike Jul 06 '18 at 06:57
Stupid question, perhaps, but are error_reporting and display_errors set? Were you able to log your all your headers per request and make sure they're kosher (#2 in the answer linked)? Finally, are you sure your thread is reaching the correct exit point (#1 in the answer linked)? – Chris Slothouber Jul 06 '18 at 11:25
After having my morning beverage, I can't locate any of your PHP error reporting configuration. Do you have PHP error logging enabled? Please considering the following link to enable PHP error logging: https://serverfault.com/questions/831249/enable-error-logging-on-php-fpm-7-with-nginx – Chris Slothouber Jul 06 '18 at 14:44
So, I edited the post, but it appears to be a Varnish issue. – Mike Jul 09 '18 at 00:59
Is it possible the POST `content-length` is being mangled somewhere along the line between when nginx passes it on to varnish and varnish to the 8080 instance of nginx? One way to test this out would be to turn on header logging at all three hops in the HTTP request. Comparing the 443 nginx header log entry with that of varnish, and finally how it arrives at 8080 nginx may yield informative results. – Chris Slothouber Jul 09 '18 at 01:40

Danila Vershinin · Answer 2 · 2018-07-07T21:53:16.803

1

You may want to uncomment:

proxy_buffer_size    256k;
proxy_buffers     32 256k;

And play around with both fastcgi_buffer* and proxy_buffer* set of values if things still do not work following that. (likely have to increase).

nginx must be able to accomodate the HTTP headers within memory, and apparently your app sets too lengthy ones (Set-Cookie, etc.).

Long story here explains how to find proper value for proxy_buffer_size.

edited Jul 07 '18 at 21:53

answered Jul 06 '18 at 05:31

Danila Vershinin

8,725
2
29
35

can you explain in a little more detail what you mean by "nginx must be able to accomodate the HTTP headers within memory, and apparently your app sets too lengthy ones (Set-Cookie, etc.)." ... how would I change the nginx settings? – Mike Jul 06 '18 at 06:56
See the addition to my answer. Nginx always buffers reponse headers. So if your app sends too many headers / too long ones, this may exceed the default 4k|8k. Note that the `proxy_buffer_size` and `fastcgi_buffer_size` have to be set virtually to the same value, because the HTTP headers sent by your app are only slightly modified "on the way" out to the client (from nginx to Varnish, to "SSL nginx"). – Danila Vershinin Jul 07 '18 at 21:58

score 0 · Accepted Answer · answered Jul 12 '18 at 01:13

So the answer isnt the best, but it seems to have settled it down.

I bypassed Varnish and setup nginx cache. With little to no impact on page speed.

The base configurations were correct, and without Varnish the errors went away.

Not the best, but, it works.

upstream sent too big header while reading response header from upstream, client (nginx, varnish)

3 Answers3