Haproxy doesn't retry to another backend on 503 error

[Ilya]

Hi,
Could you help me on below issue?
I have haproxy-2.0.17-1.el7.x86_64 under RHEL7_7.
Here is config:

defaults
mode http
log global
option httplog
option dontlognull
option http-server-close
option forwardfor except 127.0.0.0/8
retries 3
timeout http-request 10s
timeout queue 10s
timeout connect 10s
timeout client 1m
timeout server 1m
timeout http-keep-alive 10s
timeout check 10s
maxconn 200

frontend main
bind 192.168.10.2:8185
# if SOAPAction is found, route it to APPGW SOAP endpoint
acl soap_hdr req.hdr(SOAPAction) -m found

acl whitelist1 src 192.168.0.0/14
acl whitelist2 src 192.168.1.28/31 192.168.2.213/31 192.168.2.232/31

tcp-request connection reject if !whitelist1 !whitelist2


use_backend cmpsoap if soap_hdr


# if URL is /Air, route to AIR backend
acl cmpair url /Air
use_backend cmpair if cmpair

# if URL is /pretups, route to ERS backend
#acl cmpers url /pretups
acl cmpers url /pretups/C2SReceiver?REQUEST_GATEWAY_CODE=IRIS&REQUEST_GATEWAY_TYPE=EXTGW&LOGIN=test_iris&PASSWORD=25de0ca33253864357b8dd07805c26a1&SOURCE_TYPE=EXTGW&SERVICE_PORT=190
use_backend cmpers if cmpers

default_backend             cmphttp

backend cmpsoap
balance roundrobin
option redispatch
retry-on conn-failure 503
server cmpsoap1 192.168.10.8:8086 maxconn 20 check
server cmpsoap2 192.168.10.11:8086 maxconn 20 check

As you can see, I have retry-on option for conn-failure and 503 error.
But haproxy does not retry to another backend on 503 error during I send SOAP request to frontend 192.168.10.2:8185. Please see haproxy logs were wrote during test:

Aug 25 08:56:17 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:56:17.553] main cmpsoap/cmpsoap1 0/0/0/78/78 200 4347 - - ---- 1/1/0/0/0 0/0 “POST / HTTP/1.1”
Aug 25 08:56:18 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:56:18.249] main cmpsoap/cmpsoap2 0/0/1/97/98 200 4347 - - ---- 1/1/0/0/0 0/0 “POST / HTTP/1.1”
Aug 25 08:56:19 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:56:19.122] main cmpsoap/cmpsoap1 1/0/0/51/52 200 4347 - - ---- 1/1/0/0/0 0/0 “POST / HTTP/1.1”
Aug 25 08:56:20 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:56:20.005] main cmpsoap/cmpsoap2 0/0/0/90/90 200 4347 - - ---- 1/1/0/0/0 0/0 “POST / HTTP/1.1”

At this moment I started to stop soap server application on 192.168.10.8 host (it is server cmpsoap1 in backend configuration).
And 503 errors appeared in log.

Aug 25 08:56:20 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:56:20.862] main cmpsoap/cmpsoap1 0/0/0/0/0 503 125 - - ---- 1/1/0/0/0 0/0 “POST / HTTP/1.1”
Aug 25 08:56:21 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:56:21.406] main cmpsoap/cmpsoap2 0/0/0/99/99 200 4347 - - ---- 1/1/0/0/0 0/0 “POST / HTTP/1.1”
Aug 25 08:56:22 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:56:22.300] main cmpsoap/cmpsoap1 0/0/0/0/0 503 125 - - ---- 1/1/0/0/0 0/0 “POST / HTTP/1.1”
Aug 25 08:56:23 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:56:23.235] main cmpsoap/cmpsoap2 0/0/0/74/74 200 4347 - - ---- 1/1/0/0/0 0/0 “POST / HTTP/1.1”

At this moment soap server was almost stopped, and you can see that haproxy started to retry.

Aug 25 08:57:17 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:57:17.212] main cmpsoap/cmpsoap2 0/0/1/73/74 200 4347 - - ---- 1/1/0/0/+1 0/0 “POST / HTTP/1.1”
Aug 25 08:57:18 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:57:17.983] main cmpsoap/cmpsoap2 0/0/1/100/101 200 4347 - - ---- 1/1/0/0/+1 0/0 “POST / HTTP/1.1”
Aug 25 08:57:19 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:57:18.921] main cmpsoap/cmpsoap2 0/0/1/85/86 200 4347 - - ---- 1/1/0/0/+1 0/0 “POST / HTTP/1.1”
Aug 25 08:57:19 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:57:19.577] main cmpsoap/cmpsoap2 0/0/0/116/116 200 4347 - - ---- 1/1/0/0/+1 0/0 “POST / HTTP/1.1”
Aug 25 08:57:20 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:57:20.581] main cmpsoap/cmpsoap2 0/0/1/161/162 200 4347 - - ---- 1/1/0/0/+1 0/0 “POST / HTTP/1.1”
Aug 25 08:57:21 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:57:21.375] main cmpsoap/cmpsoap2 0/0/1/140/141 200 4347 - - ---- 1/1/0/0/+1 0/0 “POST / HTTP/1.1”

After several seconds application was fully stopped. And haproxy started to send requests to soap2 backend server only.

Aug 25 08:57:21 localhost haproxy[35252]: Server cmphttp/cmphttp1 is DOWN, reason: Layer4 connection problem, info: “Connection refused”, check duration: 0ms. 1 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
Aug 25 08:57:22 localhost haproxy[35252]: Server cmpsoap/cmpsoap1 is DOWN, reason: Layer4 connection problem, info: “Connection refused”, check duration: 0ms. 1 active and 0 backup servers left. 2 sessions active, 0 requeued, 0 remaining in queue.
Aug 25 08:57:22 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:57:22.414] main cmpsoap/cmpsoap2 0/0/1/73/74 200 4347 - - ---- 1/1/0/0/0 0/0 “POST / HTTP/1.1”
Aug 25 08:57:23 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:57:23.478] main cmpsoap/cmpsoap2 0/0/1/60/61 200 4347 - - ---- 1/1/0/0/0 0/0 “POST / HTTP/1.1”
Aug 25 08:57:24 localhost haproxy[35252]: 192.168.2.213:52079 [25/Aug/2020:08:57:24.361] main cmpsoap/cmpsoap2 0/0/1/83/84 200 4347 - - ---- 1/1/0/0/0 0/0 “POST / HTTP/1.1”

What do you think what is the reason of such behavior? Why haproxy does not retry on 503 error?

[Ilya]

Hi! One comment more from my side.
In scope of discovering of root cause of this issue is it possible to suggest that haproxy rpm was made somehow incorrectly? May be something key wasn’t included in rpm spec and therefore haproxy doesn’t retry on 503 error?
Here is haproxy spec for rpm, it was taken from RHEL packet earlier version:

haproxy.spec

%{?scl:%scl_package haproxy}
%{!?scl:%global pkg_name %{name}}

%define haproxy_user haproxy
%define haproxy_group %{haproxy_user}
%define haproxy_home %{_root_localstatedir}/lib/haproxy
%define haproxy_confdir %{_sysconfdir}/haproxy
%define haproxy_datadir %{_datadir}/haproxy

%global _hardened_build 1

%if 0%{!?scl:1}
%global _root_sbindir %{_sbindir}
%global _root_sysconfdir %{_sysconfdir}
%global _root_localstatedir %{_localstatedir}
%endif

Name: %{?scl_prefix}haproxy
Version: 2.0.17
Release: 1%{?dist}
Summary: TCP/HTTP proxy and load balancer for high availability environments

Group: System Environment/Daemons
License: GPLv2+

URL: http://www.haproxy.org/
Source0: http://www.haproxy.org/download/2.0/src/%{pkg_name}-%{version}.tar.gz
Source1: %{pkg_name}.service
Source2: %{pkg_name}.cfg
Source3: %{pkg_name}.logrotate
Source4: %{pkg_name}.sysconfig
Source5: halog.1

BuildRequires: pcre-devel
BuildRequires: zlib-devel
BuildRequires: openssl-devel
BuildRequires: systemd-units
BuildRequires: systemd-devel
%if 0%{!?scl:1}
BuildRequires: scl-utils-build
%endif

%{?scl:Requires: %scl_runtime}

Requires(pre): shadow-utils
Requires(post): systemd
Requires(preun): systemd
Requires(postun): systemd

%description
HAProxy is a TCP/HTTP reverse proxy which is particularly suited for high
availability environments. Indeed, it can:

• route HTTP requests depending on statically assigned cookies
• spread load among several servers while assuring server persistence
  through the use of HTTP cookies
• switch to backup servers in the event a main server fails
• accept connections to special ports dedicated to service monitoring
• stop accepting connections without breaking existing ones
• add, modify, and delete HTTP headers in both directions
• block requests matching particular patterns
• report detailed status to authenticated users from a URI
  intercepted by the application

%if 0%{?scl:1}
%scl_syspaths_package -d
%endif

%prep
%setup -q -n %{pkg_name}-%{version}

%build
regparm_opts=
%ifarch %ix86 x86_64
regparm_opts=“USE_REGPARM=1”
%endif

%{__make} %{?_smp_mflags} CPU=“generic” TARGET=“linux-glibc” USE_OPENSSL=1 USE_PCRE=1 USE_ZLIB=1 USE_CRYPT_H=1 USE_SYSTEMD=1 USE_LINUX_TPROXY=1 USE_GETADDRINFO=1 ${regparm_opts} ADDINC="%{optflags}" ADDLIB="%{__global_ldflags}"

pushd contrib/halog
%{__make} halog OPTIMIZE="%{optflags}" LDFLAGS=
popd

pushd contrib/iprange
%{__make} iprange OPTIMIZE="%{optflags}" LDFLAGS=
popd

%install
%{__make} install-bin DESTDIR=%{buildroot} PREFIX=%{_prefix} TARGET=“linux-glibc”
%{__make} install-man DESTDIR=%{buildroot} PREFIX=%{_prefix}

%{__install} -p -D -m 0644 %{SOURCE1} %{buildroot}%{_unitdir}/%{name}.service
%{__install} -p -D -m 0644 %{SOURCE2} %{buildroot}%{haproxy_confdir}/%{pkg_name}.cfg
%{__install} -p -D -m 0644 %{SOURCE3} %{buildroot}%{_root_sysconfdir}/logrotate.d/%{name}
%{__install} -p -D -m 0644 %{SOURCE4} %{buildroot}%{_root_sysconfdir}/sysconfig/%{name}
%{__install} -p -D -m 0644 %{SOURCE5} %{buildroot}%{_mandir}/man1/halog.1
%{__install} -d -m 0755 %{buildroot}%{haproxy_home}
%if 0%{?scl:1}
%{__install} -d -m 0755 %{buildroot}%{_localstatedir}/lib/%{pkg_name}
%endif
%{__install} -d -m 0755 %{buildroot}%{haproxy_datadir}
%{__install} -d -m 0755 %{buildroot}%{_bindir}
%{__install} -p -m 0755 ./contrib/halog/halog %{buildroot}%{_bindir}/halog
%{__install} -p -m 0755 ./contrib/iprange/iprange %{buildroot}%{_bindir}/iprange
%{__install} -p -m 0644 ./examples/errorfiles/* %{buildroot}%{haproxy_datadir}

for httpfile in $(find ./examples/errorfiles/ -type f)
do
%{__install} -p -m 0644 $httpfile %{buildroot}%{haproxy_datadir}
done

%{__rm} -rf ./examples/errorfiles/

find ./examples/* -type f ! -name “*.cfg” -exec %{__rm} -f “{}” ;

for textfile in $(find ./ -type f -name “*.txt” -o -name README)
do
%{__mv} $textfile $textfile.old
iconv --from-code ISO8859-1 --to-code UTF-8 --output $textfile $textfile.old
%{__rm} -f $textfile.old
done

scl paths fixes

%if 0%{?scl:1}
sed -i
-e ‘s|%{_root_sysconfdir}/sysconfig/%{pkg_name}|%{_root_sysconfdir}/sysconfig/%{name}|g’
-e ‘s|%{_root_sbindir}|%{_sbindir}|g’
-e ‘s|/run/%{pkg_name}.pid|/run/%{name}.pid|g’
-e ‘s|%{_root_sysconfdir}/haproxy|%{haproxy_confdir}|g’
%{buildroot}%{_unitdir}/%{name}.service

sed -i
-e ‘s|%{_root_localstatedir}/log|%{_localstatedir}/log|g’
-e ‘s|%{_root_localstatedir}/lib/%{pkg_name}|%{_localstatedir}/lib/%{pkg_name}|g’
-e ‘s|/run/%{pkg_name}|/run/%{name}|g’
%{buildroot}%{haproxy_confdir}/%{pkg_name}.cfg

sed -i
-e ‘s|%{_root_localstatedir}/log|%{_localstatedir}/log|g’
%{buildroot}%{_root_sysconfdir}/logrotate.d/%{name}

%scl_syspaths_install_wrapper -n haproxy -m link %{haproxy_confdir}/%{pkg_name}.cfg %{_root_sysconfdir}/haproxy/%{pkg_name}.cfg
%scl_syspaths_install_wrapper -n haproxy -m link %{_unitdir}/%{name}.service %{_unitdir}/%{pkg_name}.service

%endif

%pre
getent group %{haproxy_group} >/dev/null || groupadd -f -g 188 -r %{haproxy_group}
if ! getent passwd %{haproxy_user} >/dev/null ; then
if ! getent passwd 188 >/dev/null ; then
useradd -r -u 188 -g %{haproxy_group} -d %{haproxy_home} -s /sbin/nologin -c “haproxy” %{haproxy_user}
else
useradd -r -g %{haproxy_group} -d %{haproxy_home} -s /sbin/nologin -c “haproxy” %{haproxy_user}
fi
fi

%post
%systemd_post %{name}.service
%if 0%{?scl:1}
semanage fcontext -d “%{_unitdir}/%{name}.service” >/dev/null 2>&1 || :
semanage fcontext -a -e “%{_unitdir}/%{pkg_name}.service” “%{_unitdir}/%{name}.service” >/dev/null 2>&1 || :
semanage fcontext -a -e /var/run/%{pkg_name}.sock /var/run/%{name}.sock
semanage fcontext -a -e /var/run/%{pkg_name}.stat /var/run/%{name}.stat
selinuxenabled && load_policy || :
restorecon -R “%{?_scl_root}/” >/dev/null 2>&1 || :
restorecon -R “%{_sysconfdir}” >/dev/null 2>&1 || :
restorecon -R “%{_localstatedir}” >/dev/null 2>&1 || :
restorecon “%{_unitdir}/%{name}.service” >/dev/null 2>&1 || :
%endif

%preun
%systemd_preun %{name}.service

%postun
%systemd_postun_with_restart %{name}.service

%files
%defattr(-,root,root,-)
%doc doc/* examples/
%doc CHANGELOG LICENSE README ROADMAP VERSION
%dir %{haproxy_confdir}
%dir %{haproxy_datadir}
%{haproxy_datadir}/*
%config(noreplace) %{haproxy_confdir}/%{pkg_name}.cfg
%config(noreplace) %{_root_sysconfdir}/logrotate.d/%{name}
%config(noreplace) %{_root_sysconfdir}/sysconfig/%{name}
%{_unitdir}/%{name}.service
%{_sbindir}/%{pkg_name}
%{_bindir}/halog
%{_bindir}/iprange
%{_mandir}/man1/*
%attr(-,%{haproxy_user},%{haproxy_group}) %dir %{haproxy_home}
%if 0%{?scl:1}
%attr(-,%{haproxy_user},%{haproxy_group}) %dir %{_localstatedir}/lib/%{pkg_name}
%endif

%if 0%{?scl:1}
%scl_syspaths_files -n %{pkg_name}
%endif

%changelog

• Wed Jan 09 2019 Ryan O’Hara rohara@redhat.com - 1.8.17-1

• Update to 1.8.17 (#1660514)
• Resolve CVE-2018-20615 (#1663084)

• Tue Dec 18 2018 Ryan O’Hara rohara@redhat.com - 1.8.15-1

• Update to 1.8.15 (#1660514)
• Build with new OpenSLL for ALPN support (#1595865)
• Fix seemless reloads for send-proxy/accept-proxy (#1649041)
• Resolve CVE-2018-11469 (#1584788)
• Resolve CVE-2018-20102 (#1659017)
• Resolve CVE-2018-20103 (#1659018)

• Wed Sep 19 2018 Ryan O’Hara rohara@redhat.com - 1.8.4-3

• Fix improper sign check on the header index value (#1630503)

• Tue May 01 2018 Ryan O’Hara rohara@redhat.com - 1.8.4-2

• Fix incorrect HTTP/2 frame length check (#1569808)

• Thu Nov 30 2017 Ryan O’Hara rohara@redhat.com - 1.8.4-1

• Initial packaging (#1536138)

[Ilya]

Good day, everybody!
I’ll be much appreciated if experts get me any useful advice.
Thanks in advance.

[rbassete]

Hello Ilya,

Did you find the cause or any solution?

[lukastribus]

Also see:

Redispatch ERROR 503

Redispatch is NOT a magic bullet for server problems, and all those 503 are server generated. https://cbonte.github.io/haproxy-dconv/2.2/configuration.html#4.2-retry-on Requests not fitting in a single buffer will never be retried (see the global tune.bufsize setting). Many of those requests are POST requests and probably don’t fit the buffer size.