FlashMQ randomly dropping incoming SSL connections

[jmorgade]

Flashmq randomly drops incoming SSL connections.

Besides the inline logs I share down bellow, I attach the related flasmq.log report.

The test is done with the latest tag (v1.10.0) on a Fedora 39 (Linux 6.7.7-200.fc39.x86_64) but I am facing similar issues after building docker image.

Just in case it helps, I'm using same environment to run similar tests against other MQTT brokers (emqx, hivemq, vernemq, mosquitto) and they seem to run smoothly at this point so I wonder if I am missing any fundamental config setting ? (see flashmq.conf bellow).

FlashMQ running instance

./FlashMQBuildRelease/flashmq -c flashmq.conf
[2024-03-13 10:00:11.311] [NOTICE] Loading config. Reload: false.
[2024-03-13 10:00:11.318] [NOTICE] Creating IPv4 SSL TCP listener on [0.0.0.0]:8883
[2024-03-13 10:00:11.319] [NOTICE] Creating IPv6 SSL TCP listener on [::0]:8883
[2024-03-13 10:00:11.319] [NOTICE] Creating IPv4 SSL TCP listener on [0.0.0.0]:8883
[2024-03-13 10:00:11.319] [NOTICE] Creating IPv6 SSL TCP listener on [::]:8883
[2024-03-13 10:00:11.319] [NOTICE] Creating IPv4 non-SSL TCP listener on [0.0.0.0]:1883
[2024-03-13 10:00:11.319] [INFO] Loading './str/bridgenames.db'
[2024-03-13 10:00:11.320] [INFO] Setting rlimit nofile to 1000000.
[2024-03-13 10:00:11.320] [NOTICE] 8 CPUs are detected, making as many threads. Use 'thread_count' setting to override.
[2024-03-13 10:00:11.320] [INFO] Loading './str/retained.db'
[2024-03-13 10:00:11.320] [INFO] Loading './str/sessions.db'
[2024-03-13 10:00:11.321] [NOTICE] Starting FlashMQ version 1.10.0, release build with SSE4.2 support.
[2024-03-13 10:00:11.321] [INFO] Switching logging from stdout to logfile './flashmq.log'

MqttLoadSimulator already reports dropped connections

./MqttLoadSimulator --hostname localhost --port 8883 --client-certificate ./new2/client.crt --client-private-key ./new2/client.key --ssl --delay 10
Version: 1.5.0.
Clients: 2 on 8 threads. Sent: 175 (25/s). Recv: 175 (25/s). Recv-Sent: 0. Connects: 2 (0/s). Disconnects: 2 (0/s). Errors: 4 (0/s).
Message latency (min/avg/max): 0.4 ms / 0.7 ms / 1.1 ms.
Thread loop drift: Avg: 1.00 ms, max: 1 ms (OK)

Similar behavior with other benchmark tools like "mqtt-bechmark"

mqtt-benchmark --broker tls://localhost:8883 --count 10 --size 100 --clients 10 --qos 1 --format text -broker-ca-cert ./new2/ca.crt -client-cert ./new2/client.crt -client-key ./new2/client.key
2024/03/13 10:01:10 Starting client  0
2024/03/13 10:01:10 Starting client  1
2024/03/13 10:01:10 Starting client  2
2024/03/13 10:01:10 Starting client  3
2024/03/13 10:01:10 Starting client  4
2024/03/13 10:01:10 Starting client  5
2024/03/13 10:01:10 Starting client  6
2024/03/13 10:01:10 Starting client  7
2024/03/13 10:01:10 Starting client  8
2024/03/13 10:01:10 Starting client  9
2024/03/13 10:01:10 CLIENT 4 had error connecting to the broker: not Authorized
2024/03/13 10:01:10 CLIENT 8 had error connecting to the broker: not Authorized
2024/03/13 10:01:10 CLIENT 0 had error connecting to the broker: not Authorized
2024/03/13 10:01:10 CLIENT 9 had error connecting to the broker: not Authorized
2024/03/13 10:01:10 CLIENT 6 had error connecting to the broker: not Authorized
2024/03/13 10:01:10 CLIENT 1 had error connecting to the broker: not Authorized
2024/03/13 10:01:10 CLIENT 3 is connected to the broker tls://localhost:8883
2024/03/13 10:01:10 CLIENT 7 is connected to the broker tls://localhost:8883
2024/03/13 10:01:10 CLIENT 5 is connected to the broker tls://localhost:8883
2024/03/13 10:01:10 CLIENT 2 is connected to the broker tls://localhost:8883

flashmq.conf

log_file    ./flashmq.log
storage_dir ./str

listen {
  protocol mqtt
  inet_protocol ip4_ip6
  inet4_bind_address 0.0.0.0
  inet6_bind_address ::0
  fullchain ./new2/server.crt
  privkey ./new2/server.key

  # default = 8883
  port 8883
}

listen {
  protocol mqtt
  fullchain ./new2/server.crt
  privkey ./new2/server.key
  client_verification_ca_file ./new2/ca.crt
  client_verification_still_do_authn false
}

listen {
  protocol mqtt
  inet_protocol ip4

  # default = 1883
  port 1883
}

flashmq.log

[bigsmoke]

What does the FlashMQ logfile say during the dropping of those connections?

[halfgaar]

The log was attached.

I can look in more detail later, but I see stuff like this in the log:

username='172.21.0.3,127.0.0.1,192.168.1.199,172.21.0.2'

And

User '' access denied

Can you create a clear case, with proper anonymous or non-anonymous logins clearly defined, and don't make mistakes in address/hostname vs username arguments?

[jmorgade]

Now I see, It looks like related with the self signed certificate and the subject CN entries I have there ...

Let me review the way I am generating the self signed certificates. The basic script I've been using was working smoothly with other brokers so I must confess I did not pay much attention on this.

However, if there is something wrong with the certificate, still don't quite understand why few connections are accepted.

[halfgaar]

However, if there is something wrong with the certificate, still don't quite understand why few connections are accepted.

You have overlapping listeners. The clients that are hitting the one with x509 auth get IP addresses from your CN as username. The one that are hitting the other one, get an empty string, and that is not allowed, because you config doesn't allow anonymous.

[jmorgade]

Oh, my bad, you absolutely right. I missed the anonymous flag ... now is working like a charm.

Thanks a lot!

[halfgaar]

Ah, great. So, we'll call it crisis averted ;)