search

eclipse-mosquitto / mosquitto

Eclipse Mosquitto - An open source MQTT broker
https://mosquitto.org
Other
9.08k stars 2.4k forks source link

mosquitto 2.0.18 - Job for mosquitto.service failed because a timeout was exceeded: poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 0 (Timeout) #3076

Open mrdc opened 4 months ago

mrdc commented 4 months ago

Hi,

I've used mosquitto 1.6.10 for a long time and recently has updated to 2.0.18 (built from sources). When I try systemctl start mosquitto.service I receive this error: Job for mosquitto.service failed because a timeout was exceeded.

Versions:

CentOS Linux release 7.9.2009 (Core)
3.10.0-1160.88.1.el7.centos.plus.x86_64

mosquitto: https://mosquitto.org/files/source/mosquitto-2.0.18.tar.gz

make WITH_WEBSOCKETS=yes
make install

WebSockets: https://github.com/warmcat/libwebsockets/archive/refs/tags/v4.3.3.tar.gz

cd libwebsockets-4.3.3/
mkdir build
cd build/
cmake ..
make
make install

cJSON: https://github.com/DaveGamble/cJSON/archive/refs/tags/v1.7.18.tar.gz

make 
make install

/etc/systemd/system/mosquitto.service sudo systemctl enable mosquitto.service mosquitto.service 

[Unit]
Description=Mosquitto MQTT Broker
Documentation=man:mosquitto.conf(5) man:mosquitto(8)
After=network.target
Wants=network.target

[Service]
Type=notify
NotifyAccess=main
ExecStart=/usr/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf
ExecReload=/bin/kill -HUP $MAINPID
Restart=on-failure
ExecStartPre=/bin/mkdir -m 740 -p /var/log/mosquitto
ExecStartPre=/bin/chown mosquitto: /var/log/mosquitto
ExecStartPre=/bin/mkdir -m 740 -p /var/run/mosquitto
ExecStartPre=/bin/chown mosquitto: /var/run/mosquitto

[Install]
WantedBy=multi-user.target
# sudo systemctl start mosquitto.service
Job for mosquitto.service failed because a timeout was exceeded. See "systemctl status mosquitto.service" and "journalctl -xe" for details.
# systemctl status mosquitto.service
● mosquitto.service - Mosquitto MQTT Broker
   Loaded: loaded (/etc/systemd/system/mosquitto.service; enabled; vendor preset: disabled)
   Active: activating (start) since Wed 2024-07-03 13:12:15 xxxxxxxxxx; 1min 2s ago
     Docs: man:mosquitto.conf(5)
           man:mosquitto(8)
  Process: 32080 ExecStartPre=/bin/chown mosquitto: /var/run/mosquitto (code=exited, status=0/SUCCESS)
  Process: 32078 ExecStartPre=/bin/mkdir -m 740 -p /var/run/mosquitto (code=exited, status=0/SUCCESS)
  Process: 32076 ExecStartPre=/bin/chown mosquitto: /var/log/mosquitto (code=exited, status=0/SUCCESS)
  Process: 32075 ExecStartPre=/bin/mkdir -m 740 -p /var/log/mosquitto (code=exited, status=0/SUCCESS)
 Main PID: 32082 (mosquitto)
    Tasks: 1
   CGroup: /system.slice/mosquitto.service
           └─32082 /usr/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf

Jul 03 13:12:15 xxxxxxxxxxxxx systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Jul 03 13:12:15 xxxxxxxxxxxxx systemd[1]: Stopped Mosquitto MQTT Broker.
Jul 03 13:12:15 xxxxxxxxxxxxx systemd[1]: Starting Mosquitto MQTT Broker...

systemctl status mosquitto.service shows activating, but the mosquitto service is running:

# ps aux | grep mosqu
mosquit+ 32196  0.0  0.4  49580  4492 ?        Ss   13:13   0:00 /usr/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf

Clients are connecting to mosquitto:

2024-07-03|13:20:48: New connection from xxxxxxx on port xxxxxx.
2024-07-03|13:20:48: New client connected from xxxxxxx as xxxxxxx (p2, c1, k60, xxxxxxxxxxxxxxxxxxxxxxxx')

No errors in logs. Everything looks fine:

# tail -f /var/log/mosquitto/mosquitto.log 
2024-07-03|13:13:45: mosquitto version 2.0.18 starting
2024-07-03|13:13:45: Config loaded from /etc/mosquitto/mosquitto.conf.
2024-07-03|13:13:45: Opening ipv4 listen socket on port xx.
2024-07-03|13:13:45: Opening websockets listen socket on port xx.
2024-07-03|13:13:45: Opening ipv4 listen socket on port xx.
2024-07-03|13:13:45: Opening ipv4 listen socket on port xx.
2024-07-03|13:13:45: mosquitto version 2.0.18 running

systemctl stop mosquitto.service works as expected:

# systemctl status mosquitto.service
● mosquitto.service - Mosquitto MQTT Broker
   Loaded: loaded (/etc/systemd/system/mosquitto.service; enabled; vendor preset: disabled)
   Active: inactive (dead) since Wed 2024-07-03 13:23:00 xxxxxxxx; 3s ago
     Docs: man:mosquitto.conf(5)
           man:mosquitto(8)
  Process: 32932 ExecStart=/usr/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf (code=exited, status=0/SUCCESS)
  Process: 32930 ExecStartPre=/bin/chown mosquitto: /var/run/mosquitto (code=exited, status=0/SUCCESS)
  Process: 32928 ExecStartPre=/bin/mkdir -m 740 -p /var/run/mosquitto (code=exited, status=0/SUCCESS)
  Process: 32926 ExecStartPre=/bin/chown mosquitto: /var/log/mosquitto (code=exited, status=0/SUCCESS)
  Process: 32925 ExecStartPre=/bin/mkdir -m 740 -p /var/log/mosquitto (code=exited, status=0/SUCCESS)
 Main PID: 32932 (code=exited, status=0/SUCCESS)

Jul 03 13:22:23 xxxxxxxxxxxxx systemd[1]: mosquitto.service holdoff time over, scheduling restart.
Jul 03 13:22:23 xxxxxxxxxxxxx systemd[1]: Stopped Mosquitto MQTT Broker.
Jul 03 13:22:23 xxxxxxxxxxxxx systemd[1]: Starting Mosquitto MQTT Broker...
Jul 03 13:23:00 xxxxxxxxxxxxx systemd[1]: Stopped Mosquitto MQTT Broker.

Any ideas what's wrong?

mrdc commented 4 months ago

After some tests I see that mosquitto is being restarted by systemd for unknown reason:

tail -f /var/log/mosquitto/mosquitto.log 
2024-07-03|16:18:26: mosquitto version 2.0.18 running
2024-07-03|16:19:56: mosquitto version 2.0.18 terminating
2024-07-03|16:19:56: Saving in-memory database to /var/lib/mosquitto//mosquitto.db.
2024-07-03|16:19:57: mosquitto version 2.0.18 starting
2024-07-03|16:19:57: Config loaded from /etc/mosquitto/mosquitto.conf.
2024-07-03|16:19:57: Opening ipv4 listen socket on port xx.
2024-07-03|16:19:57: Opening websockets listen socket on port xx.
2024-07-03|16:19:57: Opening ipv4 listen socket on port xx.
2024-07-03|16:19:57: Opening ipv4 listen socket on port xx.
2024-07-03|16:19:57: mosquitto version 2.0.18 running
2024-07-03|16:22:19: mosquitto version 2.0.18 terminating
2024-07-03|16:22:19: Saving in-memory database to /var/lib/mosquitto//mosquitto.db.
2024-07-03|16:22:19: mosquitto version 2.0.18 starting
2024-07-03|16:22:19: Config loaded from /etc/mosquitto/mosquitto.conf.
2024-07-03|16:22:19: Opening ipv4 listen socket on port xx.
2024-07-03|16:22:19: Opening websockets listen socket on port xx.
2024-07-03|16:22:19: Opening ipv4 listen socket on port xx.
2024-07-03|16:22:19: Opening ipv4 listen socket on port xx.
2024-07-03|16:22:19: mosquitto version 2.0.18 running
2024-07-03|16:23:49: mosquitto version 2.0.18 terminating
2024-07-03|16:23:49: Saving in-memory database to /var/lib/mosquitto//mosquitto.db.
2024-07-03|16:23:50: mosquitto version 2.0.18 starting
2024-07-03|16:23:50: Config loaded from /etc/mosquitto/mosquitto.conf.
2024-07-03|16:23:50: Opening ipv4 listen socket on port xx.
2024-07-03|16:23:50: Opening websockets listen socket on port xx.
2024-07-03|16:23:50: Opening ipv4 listen socket on port xx.
2024-07-03|16:23:50: Opening ipv4 listen socket on port xx.
2024-07-03|16:23:50: mosquitto version 2.0.18 running
mrdc commented 4 months ago

Issue is here: 

stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2309, ...}) = 0
write(4, "2024-07-04|10:32:16: mosquitto v"..., 54) = 54
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241755, tv_nsec=167044424}) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241755, tv_nsec=167095986}) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241755, tv_nsec=167140213}) = 0
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(12, [], 1000, 100)           = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241755, tv_nsec=267641524}) = 0
poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 2 ([{fd=7, revents=POLLIN}, {fd=8, revents=POLLIN}])
read(7, "\1\0\0\0\0\0\0\0", 8)          = 8
recvmsg(8, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base=[{{len=52, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=0, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_MAIN, rtm_protocol=RTPROT_BOOT, rtm_scope=RT_SCOPE_UNIVERSE, rtm_type=RTN_UNICAST, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_MAIN}, {{nla_len=8, nla_type=RTA_GATEWAY}, xx.xx.xx.xx}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("eth0")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=24, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_MAIN, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_LINK, rtm_type=RTN_UNICAST, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_MAIN}, {{nla_len=8, nla_type=RTA_DST}, 10.8.0.0}, {{nla_len=8, nla_type=RTA_PREFSRC}, 10.8.0.1}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("tun0")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=24, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_MAIN, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_LINK, rtm_type=RTN_UNICAST, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_MAIN}, {{nla_len=8, nla_type=RTA_DST}, xx.xx.xx.xx}, {{nla_len=8, nla_type=RTA_PREFSRC}, xx.xx.xx.xx}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("eth0")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=32, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_LOCAL, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_LINK, rtm_type=RTN_BROADCAST, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_LOCAL}, {{nla_len=8, nla_type=RTA_DST}, 10.8.0.0}, {{nla_len=8, nla_type=RTA_PREFSRC}, 10.8.0.1}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("tun0")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=32, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_LOCAL, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_HOST, rtm_type=RTN_LOCAL, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_LOCAL}, {{nla_len=8, nla_type=RTA_DST}, 10.8.0.1}, {{nla_len=8, nla_type=RTA_PREFSRC}, 10.8.0.1}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("tun0")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=32, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_LOCAL, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_LINK, rtm_type=RTN_BROADCAST, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_LOCAL}, {{nla_len=8, nla_type=RTA_DST}, 10.8.0.255}, {{nla_len=8, nla_type=RTA_PREFSRC}, 10.8.0.1}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("tun0")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=32, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_LOCAL, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_LINK, rtm_type=RTN_BROADCAST, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_LOCAL}, {{nla_len=8, nla_type=RTA_DST}, 127.0.0.0}, {{nla_len=8, nla_type=RTA_PREFSRC}, 127.0.0.1}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("lo")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=8, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_LOCAL, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_HOST, rtm_type=RTN_LOCAL, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_LOCAL}, {{nla_len=8, nla_type=RTA_DST}, 127.0.0.0}, {{nla_len=8, nla_type=RTA_PREFSRC}, 127.0.0.1}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("lo")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=32, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_LOCAL, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_HOST, rtm_type=RTN_LOCAL, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_LOCAL}, {{nla_len=8, nla_type=RTA_DST}, 127.0.0.1}, {{nla_len=8, nla_type=RTA_PREFSRC}, 127.0.0.1}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("lo")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=32, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_LOCAL, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_LINK, rtm_type=RTN_BROADCAST, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_LOCAL}, {{nla_len=8, nla_type=RTA_DST}, 127.255.255.255}, {{nla_len=8, nla_type=RTA_PREFSRC}, 127.0.0.1}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("lo")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=32, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_LOCAL, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_LINK, rtm_type=RTN_BROADCAST, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_LOCAL}, {{nla_len=8, nla_type=RTA_DST}, xx.xx.xx.xx}, {{nla_len=8, nla_type=RTA_PREFSRC}, xx.xx.xx.xx}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("eth0")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=32, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_LOCAL, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_HOST, rtm_type=RTN_LOCAL, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_LOCAL}, {{nla_len=8, nla_type=RTA_DST}, xx.xx.xx.xx}, {{nla_len=8, nla_type=RTA_PREFSRC}, xx.xx.xx.xx}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("eth0")}]}, {{len=60, type=RTM_NEWROUTE, flags=NLM_F_MULTI, seq=1, pid=14219}, {rtm_family=AF_INET, rtm_dst_len=32, rtm_src_len=0, rtm_tos=0, rtm_table=RT_TABLE_LOCAL, rtm_protocol=RTPROT_KERNEL, rtm_scope=RT_SCOPE_LINK, rtm_type=RTN_BROADCAST, rtm_flags=0}, [{{nla_len=8, nla_type=RTA_TABLE}, RT_TABLE_LOCAL}, {{nla_len=8, nla_type=RTA_DST}, xx.xx.xx.xx}, {{nla_len=8, nla_type=RTA_PREFSRC}, xx.xx.xx.xx}, {{nla_len=8, nla_type=RTA_OIF}, if_nametoindex("eth0")}]}], iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 772
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
write(7, "\1\0\0\0\0\0\0\0", 8)         = 8
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(12, [], 1000, 100)           = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241213, tv_nsec=388608946}) = 0
poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 2 ([{fd=7, revents=POLLIN}, {fd=8, revents=POLLIN}])
read(7, "\10\0\0\0\0\0\0\0", 8)         = 8
recvmsg(8, {msg_name={sa_family=AF_NETLINK, nl_pid=0, nl_groups=00000000}, msg_namelen=12, msg_iov=[{iov_base={{len=20, type=NLMSG_DONE, flags=NLM_F_MULTI, seq=1, pid=13507}, 0}, iov_len=4096}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, 0) = 20
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(12, [], 1000, 100)           = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241213, tv_nsec=489596871}) = 0
poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 0 (Timeout)
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(12, [], 1000, 100)           = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241213, tv_nsec=590478023}) = 0
poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 0 (Timeout)
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(12, [], 1000, 100)           = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241213, tv_nsec=691305839}) = 0
poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 0 (Timeout)
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(12, [], 1000, 100)           = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241213, tv_nsec=791902415}) = 0
poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 0 (Timeout)
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(12, [], 1000, 100)           = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241213, tv_nsec=892551978}) = 0
poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 0 (Timeout)
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(12, [], 1000, 100)           = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241213, tv_nsec=993340802}) = 0
poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 0 (Timeout)
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(12, [], 1000, 100)           = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241214, tv_nsec=94113928}) = 0
poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 0 (Timeout)
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(12, [], 1000, 100)           = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
clock_gettime(CLOCK_BOOTTIME, {tv_sec=241214, tv_nsec=194770986}) = 0
poll([{fd=7, events=POLLIN}, {fd=8, events=POLLIN}, {fd=9, events=POLLIN}], 3, 0) = 0 (Timeout)
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], [], 8) = 0
epoll_wait(12, [], 1000, 100)           = 0

Seems to be related to these issues: https://github.com/eclipse/mosquitto/issues/986 https://github.com/eclipse/mosquitto/issues/1023

RobLeighton67 commented 1 month ago

Just to rule out something obvious - I had the same issue when I built mosquitto without the systemd build option in config.mk set ?

Daedaluz commented 1 month ago

The manpage of systemd services, under Options, more specifically the "Type" option:

Behavior of notify is similar to exec; however, it is expected that the service sends a "READY=1" notification message via sd_notify(3) or an equivalent call when it has finished starting up. systemd will proceed with starting follow-up units after this notification message has been sent. If this option is used, NotifyAccess= (see below) should be set to open access to the notification socket provided by systemd. If NotifyAccess= is missing or set to none, it will be forcibly set to main.

Digging in the source a bit, there seems to be some WITH_SYSTEMD flag you can compile with which should do just this

from the in-tree systemd service:

With WITH_SYSTEMD mosquitto will notify a complete startup after initialization. This means that follow-up units can be started after full initialization of mosquitto (i.e. sockets are opened).