1

We have an HA MariaDB cluster where our load balancer has suddenly started not being able to see our db nodes as online. We've updated our application to hit the nodes directly and bypass the load balancer because we can't figure out what's going on.

haproxy config

global
  log 127.0.0.1   local0
  log 127.0.0.1   local1 notice
  #log loghost    local0 info
  maxconn 4096
  #debug
  #quiet
  user haproxy
  group haproxy

defaults
  log     global
  mode    http
  retries 3
  timeout client 50s
  timeout connect 5s
  timeout server 50s
  option dontlognull
  option redispatch
  option tcplog
  balance  roundrobin

# Set up application listeners here.

listen admin
  bind 0.0.0.0:22002
  mode http
  stats uri /

listen mysql-cluster
  bind 0.0.0.0:3306
  balance roundrobin
  mode tcp
  server db1.my-domain.com XX.XX.XXX.94:3306 check
  server db2.my-domain.com XX.XX.XXX.97:3306 check
  server db3.my-domain.com XX.XX.XXX.96:3306 check
  option mysql-check user balance

This load balancer's sole job is to balance traffic between db nodes, not any other services. I tried enabling debugging to see more verbose output, but I can't find any errors related to the mysql-cluster check. In the logs I'll see log entries completely unrelated to the db nodes the configuration specifies. Here's an example:

Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[10] : [ttl=3]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[11] : [auth=1 866db534aa49e7d727e7c41caf33020031f26b0e]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: process_status_message: bad node [prod-load-1] in message
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG: Dumping message with 12 fields
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[0] : [t=status]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[1] : [st=active]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[2] : [dt=1388]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[3] : [protocol=1]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[4] : [src=prod-load-1]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[5] : [(1)srcuuid=0x24deb20(36 27)]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[6] : [seq=a8b208]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[7] : [hg=5792730f]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[8] : [ts=58e3e4fb]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[9] : [ld=0.00 0.01 0.05 1/223 49874]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[10] : [ttl=3]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[11] : [auth=1 xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: process_status_message: bad node [demo-load2] in message
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG: Dumping message with 10 fields
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[0] : [t=NS_ackmsg]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[1] : [dest=demo-load2]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[2] : [ackseq=2717430]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[3] : [(1)destuuid=0x24e0780(37 28)]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[4] : [src=demo-load2]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[5] : [(1)srcuuid=0x24d5540(36 27)]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[6] : [hg=5391a40d]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[7] : [ts=58e3e4fb]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[8] : [ttl=3]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[9] : [auth=1 xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: process_status_message: bad node [prod-load-1] in message
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG: Dumping message with 12 fields
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[0] : [t=status]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[1] : [st=active]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[2] : [dt=1388]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[3] : [protocol=1]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[4] : [src=prod-load-1]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[5] : [(1)srcuuid=0x24e0640(36 27)]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[6] : [seq=a8b208]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[7] : [hg=5792730f]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[8] : [ts=58e3e4fb]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[9] : [ld=0.00 0.01 0.05 1/223 49874]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[10] : [ttl=3]
Apr 04 18:24:59 database-load-balancer-1 heartbeat: [4048]: ERROR: MSG[11] : [auth=1 xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx]

What can I do to figure out why my db nodes are listed as "down"?

  • Did you mix the staging and production environment? E.g. demo-load2 and prod-load1. – 030 Apr 16 '17 at 14:59
1

First, ensure that you have mysql user named "balance" on all of your DB servers. Then ensure that user "balance" has the right to connect from the haproxy IP address and not just from the localhost.

To configure haproxy logging do the following:

You have already configured local0 syslog facility for the haproxy log in your haproxy configuration.

...
log 127.0.0.1   local0
...

Add this to the /etc/rsyslog.conf to write logs to a file.

# provides UDP syslog reception
$ModLoad imudp
$UDPServerRun 514

# haproxy logs
local0.*         /var/log/haproxy.log

Restart haproxy and rsyslog services and then check the /var/log/haproxy.log for the lines like this:

localhost haproxy[1555]: Server mysql/mysql-1 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.

This log should contain enough information to pinpoint the problem.

| improve this answer | |
  • I'm not seeing any UP/DOWN logs appear here. Only 3 log entries in the past 5 minutes, they're on ports 42856, 51251 and 51252 but don't indicate any kind of failure. – Webnet Apr 18 '17 at 18:39
  • Can you paste the logs here? Also, have you checked the haproxy stats page? It should listen on the 22002 as per configuration you have pasted here. – user373333 Apr 19 '17 at 21:42
0

You need to use the option mysql-check with the check, if you use just checke MariaDB opens a connection and keeps it open until it times out and you can run out of connections pretty quickly. The option mysql-check opens and closes the connection, but you will need a dummy user in the DB that can authenticate against the DB. You can check the HAProxy documentation

| improve this answer | |
  • 1
    Can you elaborate on what's incorrect about this configuration? I think option mysql-check user balance does what you're describing. – Webnet Apr 5 '17 at 18:01

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.