Systemd service fails to launch with option http-server-close


#1

Hello,
I am complete Newbe in HAPROXY and want to use is to redirect Websocket requests coming via port 80 to a different port 8181 on which a custom Websocket-Server is listening. All is supposed to work on the same mashine,
haproxy, Apache and the websocket Server.

I installed haproxy in Version 1.5.8 straight from the Debian 8 repositories.

The Apache Port is reconfigured from Port 80 to 8000. This works.

A properly working Websocket-Call is ws://:8181/demo

My idea is haproxy the websocket calls to ws:///demo to ws://:8181/demo
and to haproxy the Standard http-calls on port 80 to the Apache 8000.

While the Apache-hapoxy-config part seems to be fine, the ws-configuration sucks. I am not sure why and do not know really how to debug.

I was assuming that the line
option http-server-close
from a configuration sample I found would be important but with this line the Service does not start. It Fails with

haproxy.service start request repeated too quickly, refusing to start.
<<

Here is the complete config:
(a check via haproxy -c -f haproxy.cfg does not show errors)

Haproxy Konfig fuer Websockets

Berner Telecom-Dienste © 2018

Achtung: Die Einrueckungen sind TABs!!

global
log 127.0.0.1 local0
log 127.0.0.1 local1 notice
maxconn 2000
chroot /var/lib/haproxy
user haproxy
group haproxy
daemon
option http-server-close

defaults
log global
mode http
option httplog
option dontlognull
retries 3
maxconn 2000
timeout connect 5000
timeout client 50000
timeout server 50000
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 public
bind *:80
acl is_websocket hdr(Upgrade) -i WebSocket
acl is_websocket_server hdr_end(host) -i primus0.de/demo:8181
use_backend ws if is_websocket is_websocket_server
default_backend www

backend www
timeout server 30s
server www1 127.0.0.1:8000

backend ws
timeout server 600s
server ws1 127.0.0.1:8181

Any idea how to overcome this?

Best regards

Wuppi


#2

I don’t think this anything to do with “option http-server-close”. This is just about systemd rejecting repeated requests in short time. Now, there may be a underlying issue here so I suggest:

Stop haproxy. Kill it if necessary, make sure systemd status is clean. Wait a minute or 2. And then start haproxy ONCE. If it fails, provide the full output of:
systemctl status haproxy


#3

Hi,
thanks for your kind answer. However, the line ‘option http-server-close’ makes the difference wheather the service starts or not.

Uncommented it does not start and here is the output from

servicve status haproxy

systemctl status haproxy

● haproxy.service - HAProxy Load Balancer
Loaded: loaded (/lib/systemd/system/haproxy.service; enabled)
Active: failed (Result: start-limit) since Mon 2017-11-13 13:39:11 CET; 2s ago
Docs: man:haproxy(1)
file:/usr/share/doc/haproxy/configuration.txt.gz
Process: 4932 ExecStart=/usr/sbin/haproxy-systemd-wrapper -f ${CONFIG} -p /run/haproxy.pid EXTRAOPTS (code=exited, status=0/SUCCESS) Process: 8042 ExecStartPre=/usr/sbin/haproxy -f {CONFIG} -c -q (code=exited, status=1/FAILURE)
Main PID: 4932 (code=exited, status=0/SUCCESS)

Nov 13 13:39:10 v22016031783732921 systemd[1]: haproxy.service: control process exited, code=exited status=1
Nov 13 13:39:10 v22016031783732921 systemd[1]: Failed to start HAProxy Load Balancer.
Nov 13 13:39:10 v22016031783732921 systemd[1]: Unit haproxy.service entered failed state.
Nov 13 13:39:11 v22016031783732921 systemd[1]: haproxy.service holdoff time over, scheduling restart.
Nov 13 13:39:11 v22016031783732921 systemd[1]: Stopping HAProxy Load Balancer…
Nov 13 13:39:11 v22016031783732921 systemd[1]: Starting HAProxy Load Balancer…
Nov 13 13:39:11 v22016031783732921 systemd[1]: haproxy.service start request repeated too quickly, refusing to start.
Nov 13 13:39:11 v22016031783732921 systemd[1]: Failed to start HAProxy Load Balancer.
Nov 13 13:39:11 v22016031783732921 systemd[1]: Unit haproxy.service entered failed state.
root@v22016031783732921:/home/andreas#

Having said this, I am of course not sure the line would really make the configuration work as intended. Maybe you see an other potential source of the problem?

Best

Wuppi


#4

Ok, I can see what happens. You can configure this option in every section, except the global section. Please move it from the global to the default section.

Both systemd and the manual configuration check should warn about this though, so I’m not sure why we don’t see an appropriate error message.

lukas@dev:~/haproxy-1.5$ ./haproxy -v
HA-Proxy version 1.5.8 2014/10/31
Copyright 2000-2014 Willy Tarreau <w@1wt.eu>

lukas@dev:~/haproxy-1.5$ ./haproxy -c -f ../cert/slim-config.cfg
[ALERT] 316/135923 (17193) : parsing [../cert/slim-config.cfg:3] : unknown keyword 'option' in 'global' section
[ALERT] 316/135923 (17193) : Error(s) found in configuration file : ../cert/slim-config.cfg
[ALERT] 316/135923 (17193) : Fatal errors found in configuration.
lukas@dev:~/haproxy-1.5$

#5

Hi Lukas,
thanks for your answer. The good news is that the service launches now. The error is gone.
The bad news, though, is that the Websocket Connection still does not connect.

I am not sure I configured the front- and ws backend properly.

Would you mind having a look at it?

Best

Andreas


#6

The host header match is definitely wrong.

The path has nothing to do with the host header, and port 8181 is an internal port, the browser doesn’t know about it. So this should probably look like this:

acl is_websocket_server hdr(host) -i primus0.de

Anyway, why don’t you omit the host header matching for know and focus on the actual ws negotiation. You can always add stricter ACLs later, when everything is working.

More about websockets on haproxy here:


#7

Hi Lukas,
hui, the article opens a full set of new questions to me which is pretty frustrating. I honestly thought it being much easier to configure HAPROXY to my needs.

Maybe I will try first to reconfigure the apache for my purpose without haproxy. If I don’t succeed there I may refer back to you if you don’t mind.

Thanks at this time again.

Best
Wuppi


#8

Well, did you try without the host ACL?

acl is_websocket hdr(Upgrade) -i WebSocket
use_backend ws if is_websocket

#9

Hi Lukas,

my full config looks now like

Haproxy Konfig fuer Websockets

Berner Telecom-Dienste © 2018

Achtung: Die Einr▒ueckungen sind TABs!!

global
log 127.0.0.1 local0
log 127.0.0.1 local1 notice
maxconn 2000
chroot /var/lib/haproxy
user haproxy
group haproxy
daemon

defaults
log global
mode http
option httplog
option dontlognull
retries 3
maxconn 2000
timeout connect 5000
timeout client 50000
timeout server 50000
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 public
bind *:80
maxconn 60000
acl is_websocket hdr(Upgrade) -i WebSocket
use_backend ws if is_websocket
default_backend www

backend www
timeout server 30s
server www1 127.0.0.1:8000

backend ws
timeout server 600s
server ws1 127.0.0.1:8181

==========

The problem remains and I am not sure where the problem is. Maybe the backend ws declaration is buggy as well?
The Websocket-Server listens on Port 8181 and according to the logging of this Websocket-Server there is no request coming in.

How could I check what haproxy does with the request?
I don’t want to bother you too much with my problems as being really a novice.

Best

Wuppi


#10

Are you sure your websocket client is actually using an HTTP upgrade from plain to websocket?

Check your request with wireshark, it should look like this:

GET / HTTP/1.1
Upgrade: websocket
Connection: Upgrade
Sec-WebSocket-Version: 13
Sec-WebSocket-Key: avkFOZvLE0gZTtEyrZPolA==
Host: localhost:8080
Sec-WebSocket-Protocol: echo-protocol

Important is the Upgrade and Connection header. The latest haproxy configuration here specifically looks at the upgrade header, which needs to be websocket.


#11

Actually, I am just using A Standard Firefox Browser with a javascript-call like

ws = new WebSocket(“ws://primus0.de/demo”);

as a client. I guess this should not be the problem, should it?
So I am not sure a check with wireshark would really help, and on top of that I am not sure where to install and how to use in this case.

The client is local on windows and the haproxy and Websocket-Server and Apache are on a remote server

Are you familar with the logging on haproxy? I am not but isn’t there a way to easily track how the incoming request is handled? Well it seems to me that it is forwarded transparently.

If you suspect the header not being correct, could we try adding an acl rule based on the uri primus0.de/demo ?
Could you help phrasing it? Would it be a replacement for the existing acl rule?

Also, can we rediscuss the line option-http-server-close? I read somewhere something like it would prevent a subsequentially opened request from the same process to be routed to the same destination. Could that be part of the problem?

Best

Wuppi


#12

Replace the log lines in the global section with:
log 127.0.0.1 syslog debug

Make sure a syslog daemon is listening on 127.0.0.1. You should be able to see which backend and which frontend the request goes across.

You can also start haproxy manually in debug mode, this would enable you to see the actual request on the command line (so we can see if there is an upgrade header or not):

So that would be (you can stop haproxy with Ctrl-C/Strg-C):

systemctl stop haproxy
/usr/sbin/haproxy -f /etc/haproxy.cfg -d

Add an additional use_backend rule, like this (I am using anonymous ACLs here, since we don’t really need the doub:

use_backend ws if is_websocket
use_backend ws if { hdr(Host) -i primus0.de } { path /demo }
default_backend www

No, in haproxy 1.4 and older the default was tunnel mode. That means that only the first transaction in a TCP session is “seen” by haproxy and could indeed cause issues. However that is not the case for haproxy 1.5 and whatever the default in 1.4 may be, “option http-server-close” would have rectified that issue.

Generally I would recommend you to upgrade to Debian Stable, as that would also bring haproxy to the current 1.7 tree, but I do not believe that would change anything about the websocket issue.


#13

I tried the debugging mode if haproxy without changing the configuration at this time.
The result is not clear to me as I cannot really determine what haproxy saw and did.
Here is the log (I had to change the links in log in order for the forum platform to accept the log).

root@v22016031783732921:/etc/haproxy# /usr/sbin/haproxy -f /etc/haproxy/haproxy.cfg -d
Available polling systems :
epoll : pref=300, test result OK
poll : pref=200, test result OK
select : pref=150, test result FAILED
Total: 3 (2 usable), will use epoll.
Using epoll() as the polling mechanism.
00000000:public.accept(0004)=0006 from [87.139.43.187:55999]
00000000:public.clireq[0006:ffffffff]: GET /primus-agent/index.php?user=klinikherford1&passwort=geheim&server=primus0 .de&design=klinikherford HTTP/1.1
00000000:public.clihdr[0006:ffffffff]: Host: primus0 .de
00000000:public.clihdr[0006:ffffffff]: User-Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko/20100101 Firefox/57.0
00000000:public.clihdr[0006:ffffffff]: Accept: text/html,application/xhtml+xml,application/xml;q=0.9,/;q=0.8
00000000:public.clihdr[0006:ffffffff]: Accept-Language: de,en-US;q=0.7,en;q=0.3
00000000:public.clihdr[0006:ffffffff]: Accept-Encoding: gzip, deflate
00000000:public.clihdr[0006:ffffffff]: Cookie: BT_pdc=eyJldGNjX2N1c3QiOjAsImVjX29yZGVyIjowLCJldGNjX25ld3NsZXR0ZXIiOjB9; _et_coid=e7f7b750e91a3b29c7316578c7af591e
00000000:public.clihdr[0006:ffffffff]: Connection: keep-alive
00000000:public.clihdr[0006:ffffffff]: Upgrade-Insecure-Requests: 1
00000001:public.accept(0004)=0008 from [87.139.43.187:56000]
00000002:public.accept(0004)=0009 from [87.139.43.187:56001]
00000000:www.srvrep[0006:0007]: HTTP/1.1 200 OK
00000000:www.srvhdr[0006:0007]: Date: Wed, 15 Nov 2017 06:08:36 GMT
00000000:www.srvhdr[0006:0007]: Server: Apache/2.4.10 (Debian)
00000000:www.srvhdr[0006:0007]: Vary: Accept-Encoding
00000000:www.srvhdr[0006:0007]: X-Mod-Pagespeed: 1.11.33.5-0
00000000:www.srvhdr[0006:0007]: Content-Encoding: gzip
00000000:www.srvhdr[0006:0007]: Cache-Control: max-age=0, no-cache
00000000:www.srvhdr[0006:0007]: Content-Length: 13602
00000000:www.srvhdr[0006:0007]: Connection: close
00000000:www.srvhdr[0006:0007]: Content-Type: text/html; charset=UTF-8
00000003:public.clireq[0006:ffffffff]: GET /primus-agent/img/%7B%7Bschlange.statusfarbe%7D%7D.png HTTP/1.1
00000003:public.clihdr[0006:ffffffff]: Host: primus0 .de
00000003:public.clihdr[0006:ffffffff]: User-Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko/20100101 Firefox/57.0
00000003:public.clihdr[0006:ffffffff]: Accept: /
00000003:public.clihdr[0006:ffffffff]: Accept-Language: de,en-US;q=0.7,en;q=0.3
00000003:public.clihdr[0006:ffffffff]: Accept-Encoding: gzip, deflate
00000003:public.clihdr[0006:ffffffff]: Referer: primus0 .de/primus-agent/index.php?user=klinikherford1&passwort=geheim&server=primus0 .de&design=klinikherford
00000003:public.clihdr[0006:ffffffff]: Cookie: BT_pdc=eyJldGNjX2N1c3QiOjAsImVjX29yZGVyIjowLCJldGNjX25ld3NsZXR0ZXIiOjB9; _et_coid=e7f7b750e91a3b29c7316578c7af591e
00000003:public.clihdr[0006:ffffffff]: Connection: keep-alive
00000003:www.srvrep[0006:0007]: HTTP/1.1 404 Not Found
00000003:www.srvhdr[0006:0007]: Date: Wed, 15 Nov 2017 06:08:36 GMT
00000003:www.srvhdr[0006:0007]: Server: Apache/2.4.10 (Debian)
00000003:www.srvhdr[0006:0007]: Content-Length: 321
00000003:www.srvhdr[0006:0007]: Connection: close
00000003:www.srvhdr[0006:0007]: Content-Type: text/html; charset=iso-8859-1
00000005:public.accept(0004)=0007 from [87.139.43.187:56004]
00000005:public.clireq[0007:ffffffff]: GET /demo HTTP/1.1
00000005:public.clihdr[0007:ffffffff]: Host: primus0 .de
00000005:public.clihdr[0007:ffffffff]: User-Agent: Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko/20100101 Firefox/57.0
00000005:public.clihdr[0007:ffffffff]: Accept: text/html,application/xhtml+xml,application/xml;q=0.9,/;q=0.8
00000005:public.clihdr[0007:ffffffff]: Accept-Language: de,en-US;q=0.7,en;q=0.3
00000005:public.clihdr[0007:ffffffff]: Accept-Encoding: gzip, deflate
00000005:public.clihdr[0007:ffffffff]: Sec-WebSocket-Version: 13
00000005:public.clihdr[0007:ffffffff]: Origin: Mhttp://primus0 .de
00000005:public.clihdr[0007:ffffffff]: Sec-WebSocket-Extensions: permessage-deflate
00000005:public.clihdr[0007:ffffffff]: Sec-WebSocket-Key: 5pdgCKFIIONHQbl5x0EGYw==
00000005:public.clihdr[0007:ffffffff]: Cookie: BT_pdc=eyJldGNjX2N1c3QiOjAsImVjX29yZGVyIjowLCJldGNjX25ld3NsZXR0ZXIiOjB9; _et_coid=e7f7b750e91a3b29c7316578c7af591e
00000005:public.clihdr[0007:ffffffff]: Connection: keep-alive, Upgrade
00000005:public.clihdr[0007:ffffffff]: Pragma: no-cache
00000005:public.clihdr[0007:ffffffff]: Cache-Control: no-cache
00000005:public.clihdr[0007:ffffffff]: Upgrade: websocket
00000005:ws.clicls[0007:000a]
00000005:ws.closed[0007:000a]
00000002:public.clicls[0009:ffffffff]
00000002:public.closed[0009:ffffffff]
00000001:public.clicls[0008:ffffffff]
00000001:public.closed[0008:ffffffff]
00000004:public.clicls[0006:ffffffff]
00000004:public.closed[0006:ffffffff]
^C
root@v22016031783732921:/etc/haproxy#

As far as I can see there is an upgrade to Websocket but what is haprxy doing with it?

Best

Andreas


#14

It appears haproxy detected the websocket and create a TCP tunnel towards the ws backend, just like it is supposed to do.

What happens then would be in the logs.


#15

With logs,I guess you mean the logs of the Websocket-Server? The request does not hit this server which means to me that that backend definition is likely wrong:

Basically it is indended to map the websocket-call …

primus0.de:80/demo

to

primus0.de:8181/demo

The backend definition

backend ws
timeout server 600s
server ws1 127.0.0.1:8181

may be wrong for this.


#16

No, with logs I mean haproxy logs I talked about in the post before.

Well do you have your websocket backend listening on 127.0.0.1:8181 or not?


#17

I changed the Backend Definition line to

server ws1 primus0 .de:8181

(Line was modified as the forum does not allow for links.)

and it works! Many thanks to you. Can I ask you about the timeout server definition?
My connection is supposed to remain live “forever”. Would the connection itself time out or is this just
the connection request which may time out?

If the connection itself times out after 600s what would I have to phrase in order to keep the connection open forever?


#18

You can use “timeout tunnel” (relevant for Websocket and CONNECT tunnels) in the default section and set it to a few hours. But don’t go to far with it, otherwise you risk that obsolete sessions remain there forever, until you run out of maxconn values or memory.

http://cbonte.github.io/haproxy-dconv/1.5/configuration.html#4-timeout%20tunnel


#19

ok, then this should not really become a problem as I am using kind of a ping within the connection anyway.
This should allow me to keep the connection open forever. If the connection is really lost and not properly closed the timer should indeed abort it.

Background is that I am running queuing systems for public administrations and the display connection is not supposed to be shut down.