Hi all,
Basically I want to enable http/2 protocol on my HAproxy. I successfully upgraded from v1.7.5 to v1.8.28 and as per examples added alpn h2,http/1.1 to my bind where ssl crt already was like so
After reloading config and trying to access my page, it shows 400 Bad request error from HAproxy and in logs it shows this with CH flag frontend~ backend/backend-server 0/0/1/-1/2 400 188 - - CH-- 2/2/0/0/0 0/0 "GET / HTTP/1.1"
Everything works fine if I dont add alpn h2,http/1.1 to config.
Also I noticed that if I bypass nginx on my backend, it also works. For example I am running Rancher behind HAproxy for my apps and if I set backend to not use Rancher nginx ingress, but connect straight to dedicated port, it works.
Also it works bypassing HAproxy itself, setting Rancher nginx ingress in hosts file and accessing my app, in chrome dev tools I see that it loads using h2 protocol just fine.
Any idea what might cause the 400 bad request?
Regards
Actually after upgrading to v2.0 I have noticed a lot of CR termination status codes together with on few requests. I tried to increase maxconn setting but it does not help. Do you maybe have an idea where I could begin by debugging this issue? I am starting to think maybe to upgrade to newer version or downgrade to 1.9 instead.
To troubleshoot, use show errors on the admin socket.
To possibly workaround an invalid request (which 1.8 may not yet detect), use the option accept-invalid-http-request option. However this doesn’t work for all invalid requests.
Also make sure you are using the latest bugfix version, that would be 2.0.20 at this point, or, for 2.2 it would be 2.2.10.
root@boost-2:/etc/haproxy# haproxy -vv
HA-Proxy version 2.0.20-1~bpo9+1 2021/01/12 - https://haproxy.org/
Build options :
TARGET = linux-glibc
CPU = generic
CC = gcc
CFLAGS = -O2 -g -O2 -fdebug-prefix-map=/build/haproxy-2.0.20=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2 -fno-strict-aliasing -Wdeclaration-after-statement -fwrapv -Wno-unused-label -Wno-sign-compare -Wno-unused-parameter -Wno-old-style-declaration -Wno-ignored-qualifiers -Wno-clobbered -Wno-missing-field-initializers -Wtype-limits -Wshift-negative-value -Wshift-overflow=2 -Wduplicated-cond -Wnull-dereference
OPTIONS = USE_PCRE2=1 USE_PCRE2_JIT=1 USE_REGPARM=1 USE_OPENSSL=1 USE_LUA=1 USE_ZLIB=1 USE_SYSTEMD=1
Feature list : +EPOLL -KQUEUE -MY_EPOLL -MY_SPLICE +NETFILTER -PCRE -PCRE_JIT +PCRE2 +PCRE2_JIT +POLL -PRIVATE_CACHE +THREAD -PTHREAD_PSHARED +REGPARM -STATIC_PCRE -STATIC_PCRE2 +TPROXY +LINUX_TPROXY +LINUX_SPLICE +LIBCRYPT +CRYPT_H -VSYSCALL +GETADDRINFO +OPENSSL +LUA +FUTEX +ACCEPT4 -CLOSEFROM -MY_ACCEPT4 +ZLIB -SLZ +CPU_AFFINITY +TFO +NS +DL +RT -DEVICEATLAS -51DEGREES -WURFL +SYSTEMD -OBSOLETE_LINKER +PRCTL +THREAD_DUMP -EVPORTS
Default settings :
bufsize = 16384, maxrewrite = 1024, maxpollevents = 200
Built with multi-threading support (MAX_THREADS=64, default=8).
Built with OpenSSL version : OpenSSL 1.1.0l 10 Sep 2019
Running on OpenSSL version : OpenSSL 1.1.0j 20 Nov 2018
OpenSSL library supports TLS extensions : yes
OpenSSL library supports SNI : yes
OpenSSL library supports : TLSv1.0 TLSv1.1 TLSv1.2
Built with Lua version : Lua 5.3.3
Built with network namespace support.
Built with transparent proxy support using: IP_TRANSPARENT IPV6_TRANSPARENT IP_FREEBIND
Built with zlib version : 1.2.8
Running on zlib version : 1.2.8
Compression algorithms supported : identity("identity"), deflate("deflate"), raw-deflate("deflate"), gzip("gzip")
Built with PCRE2 version : 10.22 2016-07-29
PCRE2 library supports JIT : yes
Encrypted password support via crypt(3): yes
Built with the Prometheus exporter as a service
Available polling systems :
epoll : pref=300, test result OK
poll : pref=200, test result OK
select : pref=150, test result OK
Total: 3 (3 usable), will use epoll.
Available multiplexer protocols :
(protocols marked as <default> cannot be specified using 'proto' keyword)
h2 : mode=HTX side=FE|BE mux=H2
h2 : mode=HTTP side=FE mux=H2
<default> : mode=HTX side=FE|BE mux=H1
<default> : mode=TCP|HTTP side=FE|BE mux=PASS
Available services :
prometheus-exporter
Available filters :
[SPOE] spoe
[COMP] compression
[CACHE] cache
[TRACE] trace
Also trying to set option accept-invalid-http-request looks like did not make any change, still getting those CR in logs, max req rate is 345/s as pet stats page and this is the config from stats page -
Actually looks like the CR is caused by the alpn h2,http/1.1 setting, as removing it I can not see anything related to CR in my log now, but I can see that show errors is increasing like crazy
root@boost-2:/etc/haproxy# echo "show errors -1 request" | socat stdio /run/haproxy/admin.sock
Total events captured on [12/Mar/2021:15:51:16.397] : 3620
[12/Mar/2021:15:51:16.263] frontend frontend-http (#2): invalid request
backend <NONE> (#-1), server <NONE> (#-1), event #3619, src 80.89.72.155:2574
buffer starts at 0 (including 0 out), 16188 free,
len 196, wraps at 16336, error at position 0
H1 connection flags 0x00000000, H1 stream flags 0x00000012
H1 msg state MSG_RQBEFORE(0), H1 msg flags 0x00001400
H1 chunk len 0 bytes, H1 body len 0 bytes :
00000 \x16\x03\x01\x00\xBF\x01\x00\x00\xBB\x03\x036\xEC\xBDcj\xFD\x1E\xB9
00019+ \x0F\xD4\xACR\xCBU=\x01\xFC2j\x83\x1E\xCBgEz\x83\x9E\xC2G\xFAu\x85\x00
00044+ \x00\x1E\xC0+\xC0/\xCC\xA9\xCC\xA8\xC0,\xC00\xC0\n
00060 \xC0\t\xC0\x13\xC0\x14\x003\x009\x00/\x005\x00\n
00076 \x01\x00\x00t\x00\x00\x00\x14\x00\x12\x00\x00\x0Fmy.domain.com\x00
00105+ \x17\x00\x00\xFF\x01\x00\x01\x00\x00\n
00115 \x00\n
00117 \x00\x08\x00\x1D\x00\x17\x00\x18\x00\x19\x00\x0B\x00\x02\x01\x00\x00#
00135+ \x00\x00\x00\x10\x00\x0E\x00\x0C\x02h2\x08http/1.1\x00\x05\x00\x05\x01
00160+ \x00\x00\x00\x00\xFF\x03\x00\x00\x00\r\x00\x18\x00\x16\x04\x03\x05\x03
00178+ \x06\x03\x08\x04\x08\x05\x08\x06\x04\x01\x05\x01\x06\x01\x02\x03\x02
00195+ \x01
With alpn h2 it did not increase like that, but there were lots of CR in logs but right now there is none without alpn h2 setting.
But this disables HTTP/2 protocol on my server which was the main idea to use HAproxy v2.0
EDIT: to keep in mind, there are hundreds of reuqests coming in per second on this haproxy, but those CR errors pop out a few per 5 seconds for example.
And regarding this one, I just tried to downgrade to v1.8 on my test server and you are right, 400 bad request is caused by option httpclose on backend when using alpn h2,http/1.1
No idea why on v2.0 it still works with option httpclose but I am pretty sure this is waht causes my issues with CR in logs.
Can you suggest please what value I might try to use to replace option httpclose ?
EDIT: I just tried to remove option httpclose from backend so default keep-alive would be used and unfortunately it still throws CR error in logs using v2.0 version.
I tried to trim my config as much as possible to exclude unnecessary ACL rules and backends as most of them are similar to the ones I have here in example. IP addresses and domains have been changed for example ones.
global
maxconn 10000
log /dev/log local0
log /dev/log local1 notice
chroot /var/lib/haproxy
stats socket /run/haproxy/admin.sock mode 660 level admin
stats timeout 30s
user haproxy
group haproxy
daemon
# Default SSL material locations
ca-base /etc/ssl/certs
crt-base /etc/ssl/private
ssl-default-bind-ciphers ECDH+AESGCM:DH+AESGCM:ECDH+AES256:DH+AES256:ECDH+AES128:DH+AES:RSA+AESGCM:RSA+AES:!aNULL:!MD5:!DSS
ssl-default-bind-options no-sslv3
ssl-dh-param-file /etc/haproxy/ssl/dhparams.pem
defaults
log global
mode http
option httplog
option dontlognull
option http-ignore-probes
timeout connect 5000
timeout client 50000
timeout server 300000
timeout tunnel 70000ms
errorfile 400 /etc/haproxy/errors/400.http
errorfile 403 /etc/haproxy/errors/403.http
errorfile 408 /etc/haproxy/errors/408.http
errorfile 500 /etc/haproxy/errors/500.http
errorfile 502 /etc/haproxy/errors/502.http
errorfile 503 /etc/haproxy/errors/503.http
errorfile 504 /etc/haproxy/errors/504.http
frontend frontend-http
bind 11.11.11.22:80
bind 11.11.11.33:80
bind 11.11.11.22:443 ssl crt /etc/haproxy/ssl/certs/domain.com.pem alpn h2,http/1.1
bind 11.11.11.33:443 ssl crt /etc/haproxy/ssl/certs/domain.com.pem alpn h2,http/1.1
option accept-invalid-http-request
reqadd X-Forwarded-Proto:\ https if { ssl_fc }
reqadd X-Forwarded-Port:\ 443 if { ssl_fc }
reqadd X-Forwarded-Proto:\ http if !{ ssl_fc }
reqadd X-Forwarded-Port:\ 80 if !{ ssl_fc }
rspidel Server
http-request set-header X-GW-Client-IP %[src]
acl hdr_connection_upgrade hdr(Connection) -i upgrade
acl hdr_upgrade_websocket hdr(Upgrade) -i websocket
acl host-domain-com hdr_dom(host) -i -m reg ^(domain\.com)(:[0-9]+)?$
acl host-img-domain-com hdr_dom(host) -i -m reg ^(img)([0-9])?\.(domain\.com)(:[0-9]+)?$
use_backend backend-domain-com if host-domain-lv
use_backend backend-img-domain-com if host-img-domain-com
backend Abuse
stick-table type ip size 1m expire 30m store conn_rate(3s),conn_cur,gpc0,http_req_rate(10s),http_err_rate(20s)
backend per-src-path
stick-table type binary len 20 size 1k expire 10m store http_req_rate(10s)
backend Logger
stick-table type ip size 100k expire 30m store conn_rate(3s),gpc0,conn_cur,http_req_rate(10s),http_err_rate(10s)
backend backend-img-domain-com
option httpclose
option forwardfor
balance roundrobin
option httpchk HEAD / HTTP/1.1\r\nHost:img.domain.com
server 177 1.1.1.177:6081 check
server 100 1.1.1.100:8080 backup
backend backend-domain-com
option httpclose
option forwardfor
balance roundrobin
option httpchk HEAD / HTTP/1.1\r\nHost:domain.com
acl abuse src_http_req_rate(Logger) ge 100
acl flag_abuser src_inc_gpc0(Logger) ge 0
tcp-request content reject if abuse flag_abuser
server domain-rancher 1.1.1.21:80 check
server 100 1.1.1.100:8080 backup
Please let me know if you notice anything off. Config is kind of old and was used on v1.7 haproxy.
Actually I think we are just talking about buggy, broken clients or scans, which are supposed to fail. Or aborted requests. And the error path could be different between h2 and without it, or even with or without alpn both because of different code paths in haproxy, but also in the client.
Do you know whether real applications and browser have actual issues because of this?
Do you know if something changed in logging from version v1.7 to v2.0? Because previously on v1.7 I didnt notice anything regarding CR in logs, but then again v1.7 didnt support h2. Although today I also noticed that CR popped up on frontend which is not set to use alpn h2,http/1.1
Actually I have not received any user complains for web page (haproxy frontend) where h2 is enabled currently but there was an issue where specific URL path is forwarded from different HAproxy/nginx/varnish chain to my haproxy which then forwards to nodejs app on my end and I got complains that there were times during the day where this specific URL path would hung up for a minute or so and would return 5xx errors on their side while in my haproxy logs I would see like 50-100 or more CR errors with NOSRV in a row all logged at the same timestamp and once h2 was disabled there have not been any complains, so yes I would say that this impacts application as well. This specific URL path is being requested a lot per second, basically on all the requests when browsing page as its used for cookie consent purposes. Quite weird actually why it would hung for such a long time, like hiccup.
CR logging has been there before 1.7, however with 2.0 the HTTP handling code has basically been completely rewritten. This is more about the HTTP handling code paths than logging. You can try no option http-use-htx in your defaults section in 2.0, to downgrade to the old HTTP engine. This is not possible in newer release branches, as the old HTTP engine has been completely removed.
Ok I tried to set no option http-use-htx in defaults section as per your suggestion and I noticed that now all CR entries in logs are related to HTTP/1.1 where previously it was HTTP/2.0 in headers -
That’s just a result of the older code path triggering (everything will be downgraded to HTTP/1.1).
I’m unsure what to think of the situation. I’d suggest to file a bug on Github, that way more folks are seeing it and maybe other users seeing the same can chime in as well, collecting more informations.