0

Proxy version 1.7.9 2017/08/18

Simple GET requests made within script tags in the index file are getting dropped randomly, and instead the custom 400 error html is returned with the status code of 200. Sometimes 2-3 times in a row, sometimes not even 30 times in a row. It seems to appear completely randomly. These are js files served by a node backend static configuration.

From the server logs listening at the backend, it seems that the requests do not arrive. Accessing the file directly always work. Accessing the backend with bypassing the proxy do not reproduce the problem.

Since the Error is clearly the custom error message, it has to be HAproxy. Adding option accept-invalid-http-request, and option accept-invalid-http-response did not resolve the issue. The socat admin command's do not show any errors, and the stat's do not to count these to the 4xx responses.

I'm out of ideas. Anyone has any suggestions how to examine why this is happening?

Logs include ---- in all requests. So an index HTML file requests 7-8 files as dependency. Some css, js files as GET requests. From all those requests, sometimes one or two files are not served, but the custom error 408 HTML is served as data with response code 200. This response 200 is only visible on the browser, where it says Uncaught SyntaxError: Unexpected token < while trying to parse the HTML as JS file. Now on the log via rsyslog these requests do not show up. The backend does not log these requests either. Then, after clicking refresh the next request to the set of files is served, and if served for real, the code for them is 200. Since I just keep refreshing the page, and the content does not change, all requests should show up in all logs, with code 304. ...

global
    daemon
    maxconn 4096
    log         127.0.0.1 local2 debug
    chroot      /var/lib/haproxy
    pidfile     /var/run/haproxy.pid
    user        haproxy
    group       haproxy
    stats socket /var/lib/haproxy/stats
    ssl-default-bind-ciphers PROFILE=SYSTEM
    ssl-default-server-ciphers PROFILE=SYSTEM
    tune.ssl.default-dh-param 2048
    ssl-server-verify none
    stats socket /var/run/haproxy.stat

defaults
        mode                    http
        log                     global
        option                  httplog
        option                  dontlognull
        option http-server-close
        option forwardfor       except 127.0.0.0/8
        option                  redispatch
        retries                 3
        timeout http-request    1s
        timeout queue           1m
        timeout connect         1s
        timeout client          1m
        timeout server          1m
        timeout http-keep-alive 10s
        timeout check           10s
        maxconn                 3000
        option forwardfor
        option http-server-close
       stats enable
       stats uri /stats
       stats realm Haproxy\ Statistics
       stats auth stat:stat
        errorfile 400 /var/www/html/400.html
        errorfile 403 /var/www/html/400.html
        errorfile 408 /var/www/html/400.html
        errorfile 500 /var/www/html/500.html
        errorfile 501 /var/www/html/501.html
        errorfile 502 /var/www/html/502.html
        errorfile 503 /var/www/html/503.html
        errorfile 504 /var/www/html/504.html
        option accept-invalid-http-request
        option accept-invalid-http-response

I recognize the custom error file 400.html content in the browser, when it fails.

The content served

Browser side error

Király István
  • 377
  • 4
  • 10
  • HAProxy log entries for the failed requests are crucial for troubleshooting. – Michael - sqlbot Nov 27 '17 at 04:26
  • @Michael-sqlbot The question is how to log why that error-page was served, and why with code 200. – Király István Nov 27 '17 at 05:13
  • My first question is whether the Session State at Disconnection is logged as `----` for these requests, or if some other code combo is logged. – Michael - sqlbot Nov 27 '17 at 05:30
  • Not sure if I look at the right place, but the rsyslog logs include ---- in all requests, both the ones that are ok and the ones failing. – Király István Nov 28 '17 at 01:20
  • And the responses where you get the 400 response show up as status 200 in the HAProxy logs? While it seems unlikely, if this is true, it sounds like a bug in HAproxy that causes the wrong buffer to be written to the wire. Do you have gzipping enabled in HAProxy? If so, consider disabling it and see if that makes a difference. There was recent discussion of a possible bug with gzip and this might be a related regression. (speculation) – Michael - sqlbot Nov 28 '17 at 01:27
  • sorry, I didn't formulate right. Let me correct it extending the question. – Király István Nov 28 '17 at 01:44
  • Had no compression, but adding/removing it does not change this. .. It seems that chances for these dropouts are higher after restarting haproxy. – Király István Nov 28 '17 at 02:24
  • Oh... I think I see the problem. Don't use the 400 error file for 408. Remove that entry completely. – Michael - sqlbot Nov 28 '17 at 06:14

1 Answers1

0

As @Michael-sqlbot pointed out, errorfile 408 /var/www/html/408.html should be removed completely.

This is not just a chrome issue, but a quick search is leading to https://www.haproxy.com/blog/haproxy-and-http-errors-408-in-chrome/

Király István
  • 377
  • 4
  • 10
  • 1
    You were using the 400 error file, which was converting a relatively harmless 408 into a fatal 400. The issue was probably exacerbated by your unnecessarily short `timeout http-request` and `timeout http-keep-alive` values. There's probably no need for these to be so short -- particularly with `option http-server-close` in use, since the server connect is released between client requests. Idle client connections cost very little in terms of HAProxy resources, and leaving them open longer should improve your site's performance by requiring fewer TCP handshakes between browser and proxy. – Michael - sqlbot Nov 29 '17 at 01:14
  • Thank you, we run OK since this was resolved. – Király István Dec 10 '19 at 01:26