HAProxy community

Duplicate messages in logs

I’m noticed that Haproxy emits same message twice, with prefix like [WARNING] 237/195948 (6) : and without it. I noticed this behavior while trying to run Haproxy in Docker, but with regular syslog setup situation exactly the same.

# docker run -it --rm --name haproxy -v /root/haproxy:/etc/haproxy -p 9101:9101/tcp -p 5432:5432/tcp haproxy:2.0 -f /etc/haproxy/haproxy.cfg
Proxy stats_prometheus started.
Proxy master started.
Proxy replicas started.
[NOTICE] 237/211032 (1) : New worker #1 (7) forked
[WARNING] 237/211032 (7) : Server master/dev-db-02 is DOWN, reason: Layer7 wrong status, code: 503, info: "HTTP status check returned code <3C>503<3E>", check duration: 1ms. 2 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
Server master/dev-db-02 is DOWN, reason: Layer7 wrong status, code: 503, info: "HTTP status check returned code <3C>503<3E>", check duration: 1ms. 2 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
[WARNING] 237/211033 (7) : Server master/dev-db-03 is DOWN, reason: Layer7 wrong status, code: 503, info: "HTTP status check returned code <3C>503<3E>", check duration: 2ms. 1 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
Server master/dev-db-03 is DOWN, reason: Layer7 wrong status, code: 503, info: "HTTP status check returned code <3C>503<3E>", check duration: 2ms. 1 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
[WARNING] 237/211033 (7) : Server replicas/dev-db-01 is DOWN, reason: Layer7 wrong status, code: 503, info: "HTTP status check returned code <3C>503<3E>", check duration: 5ms. 2 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
Server replicas/dev-db-01 is DOWN, reason: Layer7 wrong status, code: 503, info: "HTTP status check returned code <3C>503<3E>", check duration: 5ms. 2 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
Connect from 172.17.0.1:45992 to 172.17.0.2:5432 (master/TCP)
Connect from 172.17.0.1:46014 to 172.17.0.2:5432 (master/TCP)

It looks like prefixed messages are emitted by master process (pid 1 in container) and non prefixed ones by worker process (pid 7).

Configuration.

global
    log stdout format raw local0
    maxconn 100
    stats timeout 30s
    pidfile /run/haproxy.pid

defaults
    log global
    mode    tcp
    retries 2
    timeout client 30m
    timeout connect 4s
    timeout server 30m
    timeout check 5s
    option  dontlognull
    default-server init-addr last,libc,none

resolvers localdns
    parse-resolv-conf

listen stats_prometheus
    bind *:9101
    mode http
    option http-use-htx
    http-request use-service prometheus-exporter if { path /metrics }
    stats enable
    stats uri /stats

listen master
    bind *:5432
    option httpchk OPTIONS /master
    http-check expect status 200
    default-server inter 3s fall 3 rise 2 on-marked-down shutdown-sessions
    server dev-db-01 dev-db-01.domain.tld:5432 maxconn 120 check resolvers localdns port 8008
    server dev-db-02 dev-db-02.domain.tld:5432 maxconn 120 check resolvers localdns port 8008
    server dev-db-03 dev-db-03.domain.tld:5432 maxconn 120 check resolvers localdns port 8008

listen replicas
    bind *:5433
    option httpchk OPTIONS /replica
    http-check expect status 200
    default-server inter 3s fall 3 rise 2 on-marked-down shutdown-sessions
    server dev-db-01 dev-db-01.domain.tld:5432 maxconn 120 check resolvers localdns port 8008
    server dev-db-02 dev-db-02.domain.tld:5432 maxconn 120 check resolvers localdns port 8008
    server dev-db-03 dev-db-03.domain.tld:5432 maxconn 120 check resolvers localdns port 8008

If log line completely omitted from global section I still get logs like

# docker run -it --rm --name haproxy -v /root/haproxy:/etc/haproxy -p 9101:9101/tcp haproxy:2.0 -f /etc/haproxy/haproxy.cfg
[NOTICE] 237/204228 (1) : New worker #1 (6) forked
[WARNING] 237/204229 (6) : Server master/dev-db-02 is DOWN, reason: Layer7 wrong status, code: 503, info: "HTTP status check returned code <3C>503<3E>", check duration: 1ms. 2 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
[WARNING] 237/204229 (6) : Server master/dev-db-03 is DOWN, reason: Layer7 wrong status, code: 503, info: "HTTP status check returned code <3C>503<3E>", check duration: 2ms. 1 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
[WARNING] 237/204230 (6) : Server replicas/dev-db-01 is DOWN, reason: Layer7 wrong status, code: 503, info: "HTTP status check returned code <3C>503<3E>", check duration: 5ms. 2 active and 0 backup servers left. 0 sessions active, 0 requeued, 0 remaining in queue.
^C[WARNING] 237/205847 (1) : Exiting Master process...
[ALERT] 237/205847 (1) : Current worker #1 (6) exited with code 130 (Interrupt)
[WARNING] 237/205847 (1) : All workers exited. Exiting... (130)

But no connections like

Connect from 172.17.0.1:45992 to 172.17.0.2:5432 (master/TCP)
Connect from 172.17.0.1:46014 to 172.17.0.2:5432 (master/TCP)

are logged.

Question - it is possible to get rid of duplicates while still preserving all other log messages? I.e. it’s possible to suppress messages like

[WARNING] 237/204229 (6) : Server master/dev-db-02 is DOWN...

from master process while still preserving messages like

[NOTICE] 237/204228 (1) : New worker #1 (6) forked

and leaving worker messages

Server master/dev-db-02 is DOWN...

intact.

Try the quite configuration (or the -q) parameter. This should limit the stdout output to what’s is actually configured with the log keyword, hopefully getting rid of the duplicates.

I have tried -q parameter already, when it present it’s almost no logs.

# docker run -it --rm --name haproxy -v /root/haproxy:/etc/haproxy -p 9101:9101/tcp haproxy:2.0 -f /etc/haproxy/haproxy.cfg -q
Proxy stats_prometheus started.
Proxy master started.
Proxy replicas started.

That’s all, no status for checks, no connections logs.

That’s what you want, isn’t it? You then configure logging as required via the log keyword.

Logging is configured.

global
    log stdout format raw local0
...
defaults
    log global
...

but with -q parameter almost no logs are emitted, at least to stdout. Probably if logging will be configured using syslog then log will be populated.

Let me research that, because this doesn’t sound like expected behavior.

Can you share the output of haproxy -vv?

HA-Proxy version 2.0.17 2020/07/31 - https://haproxy.org/
Build options :
  TARGET  = linux-glibc
  CPU     = generic
  CC      = gcc
  CFLAGS  = -O2 -g -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 -Wno-implicit-fallthrough -Wno-stringop-overflow -Wno-cast-function-type -Wtype-li
mits -Wshift-negative-value -Wshift-overflow=2 -Wduplicated-cond -Wnull-dereference
  OPTIONS = USE_PCRE2=1 USE_PCRE2_JIT=1 USE_GETADDRINFO=1 USE_OPENSSL=1 USE_LUA=1 USE_ZLIB=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 -MY_ACCEPT4 +ZLIB -SLZ +CPU_AF
FINITY +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=2).
Built with OpenSSL version : OpenSSL 1.1.1d  10 Sep 2019
Running on OpenSSL version : OpenSSL 1.1.1d  10 Sep 2019
OpenSSL library supports TLS extensions : yes
OpenSSL library supports SNI : yes
OpenSSL library supports : TLSv1.0 TLSv1.1 TLSv1.2 TLSv1.3
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.11
Running on zlib version : 1.2.11
Compression algorithms supported : identity("identity"), deflate("deflate"), raw-deflate("deflate"), gzip("gzip")
Built with PCRE2 version : 10.32 2018-09-10
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