400 Bad Request at request, http://localhost/favicon.ico

400

I'm new to nginx, and my site was just deployed to Digital Ocean. When I try to open this site from a browser, it returns a 400 Bad Request.. Request Header or Cookie Too Large error message. The developer console indicates that it has to do with the request for favicon.ico from the server.

Request header

Accept:text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,image/apng,*/*;q=0.8
Accept-Encoding:gzip, deflate
Accept-Language:en-US,en;q=0.9,ko-KR;q=0.8,ko;q=0.7
AlexaToolbar-ALX_NS_PH:AlexaToolbar/alx-4.0
Connection:keep-alive
Host:{my host ip}
Upgrade-Insecure-Requests:1
User-Agent:Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/63.0.3239.132 Safari/537.36

NGINX conf

user www-data;
worker_processes auto;
pid /run/nginx.pid;

events {
        worker_connections 768;
        # multi_accept on;
}

http {

        ##
        # Basic Settings
        ##

        sendfile on;
        tcp_nopush on;
        tcp_nodelay on;
        keepalive_timeout 65;
        types_hash_max_size 2048;
        # server_tokens off;

        # server_names_hash_bucket_size 64;
        # server_name_in_redirect off;

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

        ##
        # SSL Settings
        ##

ssl_protocols TLSv1 TLSv1.1 TLSv1.2; # Dropping SSLv3, ref: POODLE
        ssl_prefer_server_ciphers on;
    ##
    # Logging Settings
    ##

    access_log /var/log/nginx/access.log;
    error_log /var/log/nginx/error.log debug;

    ##
    # Gzip Settings
    ##

    gzip on;
    gzip_disable "msie6";

    # gzip_vary on;
    # gzip_proxied any;
    # gzip_comp_level 6;
    # gzip_buffers 16 8k;
   # gzip_http_version 1.1;
        # gzip_types text/plain text/css application/json application/javascript text/xml application/xml application/xml+rss text/javascript;
    ##
    # Virtual Host Configs
    ##

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

/etc/nginx/conf.d/ contains no files or subfolders

/etc/nginx/sites-enabled/default

server {
        listen 80 default_server;
        listen [::]:80 default_server;
      root /var/www/html;

        # Add index.php to the list if you are using PHP
        index index.html index.htm index.nginx-debian.html;

        server_name _;

        location / {
                # First attempt to serve request as file, then
                # as directory, then fall back to displaying a 404.
                try_files $uri $uri/ =404;
        }

/etc/nginx/sites-enabled/myapp

upstream myapp {
  server 159.89.123.456:80;
}

map $http_upgrade $connection_upgrade {
  default upgrade;
  '' close;
}

server {
  listen 80;
  server_name 159.89.123.456;

  location / {
      try_files $uri @proxy;
  }

  location @proxy {
    include proxy_params;
    proxy_set_header X-Real-IP $remote_addr;
    proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
    proxy_set_header Host $http_host;
    proxy_redirect off;
    proxy_pass http://159.89.123.456:80;
    proxy_http_version 1.1;
    proxy_set_header Upgrade $http_upgrade;
    proxy_set_header Connection "upgrade";
 }
}

I'd really appreciate some pointers to what might be causing this issue, and how to resolve it. Below is the error.log from nginx.

2018/02/19 06:56:22 [debug] 3499#3499: *1 http upstream request: "/favicon.ico?"
2018/02/19 06:56:22 [debug] 3499#3499: *1 http upstream process header
2018/02/19 06:56:22 [debug] 3499#3499: *1 malloc: 00005575AE6DABF0:4096
2018/02/19 06:56:22 [debug] 3499#3499: *1 recv: fd:11 424 of 4096
2018/02/19 06:56:22 [debug] 3499#3499: *1 http proxy status 400 "400 Bad Request"
2018/02/19 06:56:22 [debug] 3499#3499: *1 http proxy header: "Server: nginx/1.10.3 (Ubuntu)"
2018/02/19 06:56:22 [debug] 3499#3499: *1 http proxy header: "Date: Mon, 19 Feb 2018 06:56:22 GMT"
2018/02/19 06:56:22 [debug] 3499#3499: *1 http proxy header: "Content-Type: text/html"
2018/02/19 06:56:22 [debug] 3499#3499: *1 http proxy header: "Content-Length: 258"
2018/02/19 06:56:22 [debug] 3499#3499: *1 http proxy header: "Connection: keep-alive"
2018/02/19 06:56:22 [debug] 3499#3499: *1 http proxy header done
2018/02/19 06:56:22 [debug] 3499#3499: *1 xslt filter header
2018/02/19 06:56:22 [debug] 3499#3499: *1 **HTTP/1.1 400 Bad Request
Server: nginx/1.10.3 (Ubuntu)
Date: Mon, 19 Feb 2018 06:56:22 GMT
Content-Type: text/html
Content-Length: 258
Connection: keep-alive**

2018/02/19 06:56:22 [debug] 3499#3499: *1 write new buf t:1 f:0 00005575AE6DA880, pos 00005575AE6DA880, size: 166 file: 0, size: 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 http write filter: l:0 f:0 s:166
2018/02/19 06:56:22 [debug] 3499#3499: *1 http cacheable: 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 http proxy filter init s:400 h:0 c:0 l:258
2018/02/19 06:56:22 [debug] 3499#3499: *1 http upstream process upstream
2018/02/19 06:56:22 [debug] 3499#3499: *1 pipe read upstream: 1
2018/02/19 06:56:22 [debug] 3499#3499: *1 pipe preread: 258
2018/02/19 06:56:22 [debug] 3499#3499: *1 readv: 1, last:3672
2018/02/19 06:56:22 [debug] 3499#3499: *1 readv() not ready (11: Resource temporarily unavailable)
2018/02/19 06:56:22 [debug] 3499#3499: *1 pipe recv chain: -2
2018/02/19 06:56:22 [debug] 3499#3499: *1 pipe buf free s:0 t:1 f:0 00005575AE6DABF0, pos 00005575AE6DAC96, size: 258 file: 0, size: 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 pipe length: 258
2018/02/19 06:56:22 [debug] 3499#3499: *1 input buf #0
2018/02/19 06:56:22 [debug] 3499#3499: *1 pipe write downstream: 1
2018/02/19 06:56:22 [debug] 3499#3499: *1 pipe write downstream flush in
2018/02/19 06:56:22 [debug] 3499#3499: *1 http output filter "/favicon.ico?"
2018/02/19 06:56:22 [debug] 3499#3499: *1 http copy filter: "/favicon.ico?"
2018/02/19 06:56:22 [debug] 3499#3499: *1 image filter
2018/02/19 06:56:22 [debug] 3499#3499: *1 xslt filter body
2018/02/19 06:56:22 [debug] 3499#3499: *1 http postpone filter "/favicon.ico?" 00005575AE6DAA58
2018/02/19 06:56:22 [debug] 3499#3499: *1 write old buf t:1 f:0 00005575AE6DA880, pos 00005575AE6DA880, size: 166 file: 0, size: 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 write new buf t:1 f:0 00005575AE6DABF0, pos 00005575AE6DAC96, size: 258 file: 0, size: 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 http write filter: l:0 f:0 s:424
2018/02/19 06:56:22 [debug] 3499#3499: *1 http copy filter: 0 "/favicon.ico?"
2018/02/19 06:56:22 [debug] 3499#3499: *1 pipe write downstream done
2018/02/19 06:56:22 [debug] 3499#3499: *1 event timer: 11, old: 1519023442215, new: 1519023442222
2018/02/19 06:56:22 [debug] 3499#3499: *1 http upstream exit: 0000000000000000
2018/02/19 06:56:22 [debug] 3499#3499: *1 finalize http upstream request: 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 finalize http proxy request
2018/02/19 06:56:22 [debug] 3499#3499: *1 free rr peer 1 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 close http upstream connection: 11
2018/02/19 06:56:22 [debug] 3499#3499: *1 free: 00005575AE6D5630, unused: 48
2018/02/19 06:56:22 [debug] 3499#3499: *1 event timer del: 11: 1519023442215
2018/02/19 06:56:22 [debug] 3499#3499: *1 reusable connection: 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 http upstream temp fd: -1
2018/02/19 06:56:22 [debug] 3499#3499: *1 http output filter "/favicon.ico?"
2018/02/19 06:56:22 [debug] 3499#3499: *1 http copy filter: "/favicon.ico?"
2018/02/19 06:56:22 [debug] 3499#3499: *1 image filter
2018/02/19 06:56:22 [debug] 3499#3499: *1 xslt filter body
2018/02/19 06:56:22 [debug] 3499#3499: *1 http postpone filter "/favicon.ico?" 00007FFDCA8F4CD0
2018/02/19 06:56:22 [debug] 3499#3499: *1 write old buf t:1 f:0 00005575AE6DA880, pos 00005575AE6DA880, size: 166 file: 0, size: 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 write old buf t:1 f:0 00005575AE6DABF0, pos 00005575AE6DAC96, size: 258 file: 0, size: 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 write new buf t:0 f:0 0000000000000000, pos 0000000000000000, size: 0 file: 0, size: 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 http write filter: l:1 f:0 s:424
2018/02/19 06:56:22 [debug] 3499#3499: *1 http write filter limit 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 writev: 424 of 424
2018/02/19 06:56:22 [debug] 3499#3499: *1 http write filter 0000000000000000
2018/02/19 06:56:22 [debug] 3499#3499: *1 http copy filter: 0 "/favicon.ico?"
2018/02/19 06:56:22 [debug] 3499#3499: *1 http finalize request: 0, "/favicon.ico?" a:1, c:1
2018/02/19 06:56:22 [debug] 3499#3499: *1 set http keepalive handler
2018/02/19 06:56:22 [debug] 3499#3499: *1 http close request
2018/02/19 06:56:22 [debug] 3499#3499: *1 http log handler
2018/02/19 06:56:22 [debug] 3499#3499: *1 posix_memalign: 00005575AE6DBC00:4096 @16
2018/02/19 06:56:22 [debug] 3499#3499: *1 free: 00005575AE6DABF0
2018/02/19 06:56:22 [debug] 3499#3499: *1 free: 00005575AE6E6F80, unused: 5
2018/02/19 06:56:22 [debug] 3499#3499: *1 free: 00005575AE6D9BE0, unused: 80
2018/02/19 06:56:22 [debug] 3499#3499: *1 free: 00005575AE6DBC00, unused: 3786
2018/02/19 06:56:22 [debug] 3499#3499: *1 free: 00005575AE6F63E0
2018/02/19 06:56:22 [debug] 3499#3499: *1 hc free: 0000000000000000 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 hc busy: 0000000000000000 0
2018/02/19 06:56:22 [debug] 3499#3499: *1 reusable connection: 1
2018/02/19 06:56:22 [debug] 3499#3499: *1 event timer add: 3: 65000:1519023447222
2018/02/19 06:56:22 [debug] 3499#3499: *1 post event 00005575AE7393C0
2018/02/19 06:56:22 [debug] 3499#3499: *1 delete posted event 00005575AE7393C0
2018/02/19 06:56:22 [debug] 3499#3499: *1 http keepalive handler
2018/02/19 06:56:22 [debug] 3499#3499: *1 malloc: 00005575AE6F63E0:1024
2018/02/19 06:56:22 [debug] 3499#3499: *1 recv: fd:3 -1 of 1024
2018/02/19 06:56:22 [debug] 3499#3499: *1 recv() not ready (11: Resource temporarily unavailable)
2018/02/19 06:56:22 [debug] 3499#3499: *1 free: 00005575AE6F63E0
2018/02/19 06:56:22 [debug] 3499#3499: *21 http keepalive handler
2018/02/19 06:56:22 [debug] 3499#3499: *21 malloc: 00005575AE6F63E0:1024
2018/02/19 06:56:22 [debug] 3499#3499: *21 recv: fd:12 0 of 1024
2018/02/19 06:56:22 [info] 3499#3499: *21 client 159.89.139.178 closed keepalive connection
2018/02/19 06:56:22 [debug] 3499#3499: *21 close http connection: 12
2018/02/19 06:56:22 [debug] 3499#3499: *21 event timer del: 12: 1519023447222
2018/02/19 06:56:22 [debug] 3499#3499: *21 reusable connection: 0
2018/02/19 06:56:22 [debug] 3499#3499: *21 free: 00005575AE6F63E0
2018/02/19 06:56:22 [debug] 3499#3499: *21 free: 00005575AE6F67F0, unused: 128
2018/02/19 06:57:27 [debug] 3499#3499: *1 event timer del: 3: 1519023447222
2018/02/19 06:57:27 [debug] 3499#3499: *1 http keepalive handler
2018/02/19 06:57:27 [debug] 3499#3499: *1 close http connection: 3

Best Answer

As Michael Hampton mentioned, you config is awkward. This block: 

location / {
  try_files $uri @proxy;
}

tells nginx to serve file from /var/www/html if it exists, else proxy request to http://159.89.123.456:80 (to itself), which leads to infinite recursion for non-existent files

Related Topic