Le 17/03/2017 à 11:57, Kristjan Koppel a écrit :
Hi!

I upgraded a HAProxy instance from v1.6.10 to v1.7.3 with no changes to
configuration and I noticed that now clients connecting to a WebSocket
backend are getting disconnected after being idle for "timeout client"
time rather than the much longer "timeout tunnel" time. As I understand
it, "timeout tunnel" is supposed to override the "timeout client"
setting for WebSocket sessions and this worked fine with v1.6 and earlier.

Also, this HAProxy instance has compression enabled in the defaults
section. If I remove the compression settings from there (or if I move
them to other backends only), then "timeout tunnel" starts to work
again. So, I guess this is a bug in HAProxy v1.7?

I managed to reproduce this with the official HAProxy Docker images, a
minimal haproxy.cfg and wscat (from the Debian package node-ws) as follows:

haproxy.cfg:
global
        stats socket /run/haproxy.sock mode 660 level admin
        stats timeout 30s
        daemon

defaults
        mode    http
        timeout connect 5s
        timeout client  50s
        timeout server  60s
        timeout tunnel  15m

        compression algo gzip
        compression type text/html

listen ws_test
        bind :8000
        server wscat 172.17.0.1:8001


I started one wscat instance in listening mode for the backend:
$ wscat -l 8001

With HAProxy v1.6.11 running the above config I see the following:
$ date; wscat -c ws://172.17.0.2:8000; date
Fri Mar 17 12:10:59 EET 2017
connected (press CTRL+C to quit)
foo
< bar
disconnected
Fri Mar 17 12:26:03 EET 2017

State of the session about 30 seconds after starting the above command:
$ echo "show sess" | socat /run/haproxy.sock stdio
0x12253b0: proto=tcpv4 src=172.17.0.1:52046 fe=ws_test be=ws_test
srv=wscat ts=08 age=31s calls=4
rq[f=8848202h,i=0,an=00h,rx=14m32s,wx=,ax=]
rp[f=88048202h,i=0,an=00h,rx=14m32s,wx=,ax=] s0=[7,8h,fd=1,ex=]
s1=[7,118h,fd=2,ex=] exp=14m29s


With HAProxy v1.7.3 running the same config I see the following:
$ date; wscat -c ws://172.17.0.3:8000; date
Fri Mar 17 12:29:39 EET 2017
connected (press CTRL+C to quit)
foo
< bar
disconnected
Fri Mar 17 12:30:33 EET 2017

Obviously it takes me a bit of time to send the 2 strings manually, so
total time is a bit more than the "timeout client" value here.

State of the session about 30 seconds after starting the above command:
$ echo "show sess" | socat /run/haproxy.sock stdio
0x22a4f10: proto=tcpv4 src=172.17.0.1:55996 fe=ws_test be=ws_test
srv=wscat ts=04 age=33s calls=6 rq[f=8848000h,i=0,an=00h,rx=20s,wx=,ax=]
rp[f=88048000h,i=0,an=00h,rx=30s,wx=,ax=] s0=[7,8h,fd=1,ex=]
s1=[7,118h,fd=2,ex=] exp=20s


If I remove the compression lines from the config and try again with
HAProxy v1.7.3, then it's fine again:
$ date; wscat -c ws://172.17.0.3:8000; date
Fri Mar 17 12:35:22 EET 2017
connected (press CTRL+C to quit)
foo
< bar
disconnected
Fri Mar 17 12:50:26 EET 2017

State of the session about 30 seconds after starting the above command:
$ echo "show sess" | socat /run/haproxy.sock stdio
0x1e64500: proto=tcpv4 src=172.17.0.1:56038 fe=ws_test be=ws_test
srv=wscat ts=04 age=31s calls=5
rq[f=8848000h,i=0,an=00h,rx=14m33s,wx=,ax=]
rp[f=88048000h,i=0,an=00h,rx=14m33s,wx=,ax=] s0=[7,8h,fd=1,ex=]
s1=[7,118h,fd=2,ex=] exp=14m33s

I'll be happy to provide any additional information if needed.


Hi Kristjan,

Thanks for this detailed report. You're right. This is a bug and it was fixed in 1.8. It will soon be backported in 1.7. If you're curious, the commit fixing the bug is e600624 ("BUG/MEDIUM: filters: Fix channels synchronization in flt_end_analyze"). You can safely apply it on 1.7.3.

--
Christopher Faulet

Reply via email to