[mosquitto-dev] CPU use and message count high, but no message to be fou

[Wiebe Cazemier <wiebe@xxxxxxxxxxxx>]

Hi,

I have a Mosquitto 1.6 server (with EPOLL) with about 9100 connections that is using about 10-20% CPU. '$SYS/broker/load/messages/received/1min' and '$SYS/broker/load/messages/sent/1min' are also about 9100, but when I subscribe to '#' (which my custom auth plugin written in c++ supports for my user), I see only about 2 messages per minute: the ones of normal operation.

I seem to remember that even having thousands of connections, the CPU use was mostly 1%-2%, or 5% or so. But I don't remember if the message stats was low before; if the 9100 is new/wrong.

Before I restart it to see what happens, I'd like to ask if this is normal, and what I can do to get some more debugging info.

Does each connection require one message per minute?

More debugging output below

Regards,

Wiebe



PS: output of '$SYS/#':

$SYS/broker/uptime 3740677 seconds
$SYS/broker/clients/total 9155
$SYS/broker/clients/inactive 0
$SYS/broker/clients/disconnected 0
$SYS/broker/clients/active 9155
$SYS/broker/clients/connected 9155
$SYS/broker/load/messages/received/1min 9268.31
$SYS/broker/load/messages/received/5min 9214.63
$SYS/broker/load/messages/received/15min 9197.42
$SYS/broker/load/messages/sent/1min 9275.12
$SYS/broker/load/messages/sent/5min 9233.16
$SYS/broker/load/messages/sent/15min 9217.21
$SYS/broker/load/publish/received/1min 15.46
$SYS/broker/load/publish/received/5min 20.41
$SYS/broker/load/publish/received/15min 19.66
$SYS/broker/load/publish/sent/1min 20.68
$SYS/broker/load/publish/sent/5min 34.47
$SYS/broker/load/publish/sent/15min 34.52
$SYS/broker/load/bytes/received/1min 27762.11
$SYS/broker/load/bytes/received/5min 30675.57
$SYS/broker/load/bytes/received/15min 30740.83
$SYS/broker/load/bytes/sent/1min 22258.72
$SYS/broker/load/bytes/sent/5min 26942.58
$SYS/broker/load/bytes/sent/15min 27360.02
$SYS/broker/load/sockets/1min 41.52
$SYS/broker/load/sockets/5min 42.62
$SYS/broker/load/sockets/15min 41.94
$SYS/broker/load/connections/1min 38.04
$SYS/broker/load/connections/5min 39.80
$SYS/broker/load/connections/15min 39.18
$SYS/broker/messages/received 536248480
$SYS/broker/messages/sent 536396243
$SYS/broker/subscriptions/count 9145
$SYS/broker/heap/current 18446744073651706464
$SYS/broker/publish/messages/received 877757
$SYS/broker/publish/messages/sent 705530
$SYS/broker/publish/bytes/received 264372253
$SYS/broker/publish/bytes/sent 263511454
$SYS/broker/bytes/received 1670467528
$SYS/broker/bytes/sent 1366423873

Strace on the PID shows a lot of:

rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
read(7473, "\300", 1)                   = 1
read(7473, "\0", 1)                     = 1
write(7473, "\320\0", 2)                = 2
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(14, [{EPOLLIN, {u32=7746, u64=7746}}], 1000, 100) = 1
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
read(7746, "\300", 1)                   = 1
read(7746, "\0", 1)                     = 1
write(7746, "\320\0", 2)                = 2
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(14, [{EPOLLIN, {u32=1456, u64=1456}}], 1000, 100) = 1
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
read(1456, "\300", 1)                   = 1
read(1456, "\0", 1)                     = 1
write(1456, "\320\0", 2)                = 2