I am receiving MQTT messages from a device that is not powered on

Sorry, but this has thrown me.

Usually I have a thing happen daily. It works. Or maybe more correctly now: workED! (Past tense)

Got home and I had a notification the device was UNKNOWN.

Did some testing.
Status now:
Device POWERED OFF.

The MQTT channel is spitting message out by the bucket load.

If I empty the message queue with MQTT EXPLORER, as fast as I empty it, it starts getting messages being RECEIVED.

Stuck to what to do next.

You need to get to the commandline and look at the Mosquitto Logs in realtime to see where the messages are coming from - are you running Debian ?

If so the logs should be in /var/log/mosquitto and the log file is mosquitto.log

If you tail the file you should be able to see what is coming in

tail -f mosquitto.log | grep "textyouwanttofind"

Craig

1 Like

(Shame you couldn't have replied sooner.) :wink:

(Sorry)

Yes, I'm using Ubuntu
What am I saying.. It is a RasPi. It is BullsEye.
Sorry, you got me there for a second. :wink:

I am not sure if I FOUND the problem or simply FIXED it.
I found a loop between an IN and OUT and broke that.
It isn't a direct look and has worked forever until now.
(Used a gate node)

That stopped it and I got the other (original) problem fixed.

Re-opened the gate and things are working fine.
:confused:

But I shall note those tips and where to look so next time - Sod's law - I can maybe get to a better resolution.

Sorry, quickie:
How to I make the timestamps on the left human readable?

cat logfile | tai64nlocal

Um....

pi@TimePi:/var/log/mosquitto $ sudo cat mosquitto.log | tai64nlocal
-bash: tai64nlocal: command not found
pi@TimePi:/var/log/mosquitto $ 

Ok, kinda found that part:

After installing it:

pi@TimePi:/var/log/mosquitto $ sudo apt install daemontools
Reading package lists... Done
Building dependency tree       
Reading state information... Done
Suggested packages:
  daemontools-run | runit
The following NEW packages will be installed:
  daemontools
0 upgraded, 1 newly installed, 0 to remove and 280 not upgraded.
Need to get 48.1 kB of archives.
After this operation, 263 kB of additional disk space will be used.
Get:1 http://mirror.datamossa.io/raspbian buster/main armhf daemontools armhf 1:0.76-7 [48.1 kB]
Fetched 48.1 kB in 1s (47.7 kB/s)      
Selecting previously unselected package daemontools.
(Reading database ... 107826 files and directories currently installed.)
Preparing to unpack .../daemontools_1%3a0.76-7_armhf.deb ...
Unpacking daemontools (1:0.76-7) ...
Setting up daemontools (1:0.76-7) ...
Processing triggers for man-db (2.8.5-2) ...
pi@TimePi:/var/log/mosquitto $ sudo cat mosquitto.log | tai64nlocal
1725459570: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1725461371: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1725463173: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1725464973: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1725466774: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1725468575: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1725470376: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1725472177: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.

All you have to do is to tell mosquitto to format the timestamps as human readable.
Add to this to your mosquitto conf file, which will be either /etc/mosquitto/mosquitto.conf, or a conf file in /etc/mosquitto/conf.d if you have configured it that way.

# human readable timestamps in log
log_timestamp true
log_timestamp_format %Y-%m-%d %H:%M:%S

Then restart mosquitto
sudo systemctl restart mosquitto

1 Like

So that's in the mosquitto config file - yeah?

Though that kinda doesn't help me trying to read the existing log.

if I add the line/s as you said Mosquitto won't restart.

-- The unit mosquitto.service has entered the 'failed' state with result 'exit-code'.
Sep 13 17:50:15 TimePi systemd[1]: Failed to start Mosquitto MQTT v3.1/v3.1.1 Broker.
-- Subject: A start job for unit mosquitto.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- A start job for unit mosquitto.service has finished with a failure.
-- 
-- The job identifier is 13044910 and the job result is failed.
Sep 13 17:50:24 TimePi sudo[20602]:       pi : TTY=unknown ; PWD=/home/pi ; USER=root ; COMMAND=/usr/sbin/iwlist wlan0 scan
Sep 13 17:50:24 TimePi sudo[20602]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 13 17:50:28 TimePi sudo[20602]: pam_unix(sudo:session): session closed for user root

Take the lines out, works.

Help
:confused:

Paste the relevant section of the config file, which a few lines either side.

pi@TimePi:/etc/mosquitto $ cat mosquitto.conf 
# Place your local configuration in /etc/mosquitto/conf.d/
#
# A full description of the configuration file is at
# /usr/share/doc/mosquitto/examples/mosquitto.conf.example

pid_file /var/run/mosquitto.pid

# human readable timestamps in log
#log_timestamp true
#log_timestamp_format %Y-%m-%d %H:%M:%S

persistence true
persistence_location /var/lib/mosquitto/

log_dest file /var/log/mosquitto/mosquitto.log

include_dir /etc/mosquitto/conf.d
pi@TimePi:/etc/mosquitto $ 

The three lines are commented out..
It works.

If I make the 2 lines active, I get the error (well in the log file) I see

-- 
-- The unit mosquitto.service has entered the 'failed' state with result 'exit-code'.
Sep 13 17:50:15 TimePi systemd[1]: Failed to start Mosquitto MQTT v3.1/v3.1.1 Broker.
-- Subject: A start job for unit mosquitto.service has failed
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- A start job for unit mosquitto.service has finished with a failure.

Now, after getting it running again, I am being flooded with a LOT of messages.
(Which may be related to another problem with something happening with a lot of messages looping on a MQTT device where I had to stop the loop.
But.... Probably not.
As these are the retained messages. Not so much a loop.)

Try after the log_dest file rather than before, perhaps it doesn't like being told how to format it before being told where to put it. If it still fails, post the failing file, not the working one.

Yeah, ok.

Bad news.

pi@TimePi:/etc/mosquitto $ sudo nano mosquitto.conf 
pi@TimePi:/etc/mosquitto $ sudo systemctl stop mosquitto.service 
pi@TimePi:/etc/mosquitto $ sudo systemctl start mosquitto.service 
Job for mosquitto.service failed because the control process exited with error code.
See "systemctl status mosquitto.service" and "journalctl -xe" for details.
pi@TimePi:/etc/mosquitto $ sudo systemctl start mosquitto.service 
Job for mosquitto.service failed because the control process exited with error code.
See "systemctl status mosquitto.service" and "journalctl -xe" for details.
pi@TimePi:/etc/mosquitto $ sudo nano mosquitto.conf 
pi@TimePi:/etc/mosquitto $ sudo systemctl start mosquitto.service 
pi@TimePi:/etc/mosquitto $ 

First line, edited the file and saved.
The train then goes off the rails.

Had to go back and edit it and take the lines out.

# Place your local configuration in /etc/mosquitto/conf.d/
#
# A full description of the configuration file is at
# /usr/share/doc/mosquitto/examples/mosquitto.conf.example

# human readable timestamps in log
#log_timestamp true
#log_timestamp_format %Y-%m-%d %H:%M:%S

pid_file /var/run/mosquitte.pid

persistence true
persistence_location /var/lib/mosquitto/

log_dest file /var/log/mosquitto/mosquitto.log

include_dir /etc/mosquitto/conf.d

Are you saying it now fails even with the lines commented out?

No.

If they are as is, it works.

If I make them active I get the error.

And - adding insult to injury - I seem to have a runway look with messages which I can't find.
(Sorry, I'll stay on topic)

I said to post the file that doesn't work, after moving the lines to after the log_dest line.

Sorry...

things have got nasty here with MQTT and messages.

Standby.

Right.

Is this better?

# Place your local configuration in /etc/mosquitto/conf.d/
#
# A full description of the configuration file is at
# /usr/share/doc/mosquitto/examples/mosquitto.conf.example

pid_file /var/run/mosquitte.pid

persistence true
persistence_location /var/lib/mosquitto/

log_dest file /var/log/mosquitto/mosquitto.log

# human readable timestamps in log
log_timestamp true
log_timestamp_format %Y-%m-%d %H:%M:%S

include_dir /etc/mosquitto/conf.d

Now, trying to start it:

pi@TimePi:/etc/mosquitto $ sudo systemctl start mosquitto.service 
Job for mosquitto.service failed because the control process exited with error code.
See "systemctl status mosquitto.service" and "journalctl -xe" for details.

Doing that (tail only)

pi@TimePi:/etc/mosquitto $ journalctl -xe
Sep 13 18:52:53 TimePi systemd[1]: Starting Time & Date Service...
-- Subject: A start job for unit systemd-timedated.service has begun execution
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- A start job for unit systemd-timedated.service has begun execution.
-- 
-- The job identifier is 13051778.
Sep 13 18:52:53 TimePi dbus-daemon[428]: [system] Successfully activated service 'org.freedesktop.timedate1'
Sep 13 18:52:53 TimePi systemd[1]: Started Time & Date Service.
-- Subject: A start job for unit systemd-timedated.service has finished successfully
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- A start job for unit systemd-timedated.service has finished successfully.
-- 
-- The job identifier is 13051778.
Sep 13 18:52:53 TimePi systemd-timedated[29185]: /dev/rtc is busy. Is somebody keeping it open continuously? That's not a good idea... Returning a bogus RTC timestamp.
Sep 13 18:52:53 TimePi sudo[29180]: pam_unix(sudo:session): session closed for user root
Sep 13 18:53:04 TimePi sudo[29188]:       pi : TTY=unknown ; PWD=/home/pi ; USER=root ; COMMAND=/usr/sbin/iwlist wlan0 scan
Sep 13 18:53:04 TimePi sudo[29188]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 13 18:53:09 TimePi sudo[29188]: pam_unix(sudo:session): session closed for user root
Sep 13 18:53:17 TimePi sudo[29142]: pam_unix(sudo:session): session closed for user root
Sep 13 18:53:23 TimePi systemd[1]: systemd-timedated.service: Succeeded.
-- Subject: Unit succeeded
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- The unit systemd-timedated.service has successfully entered the 'dead' state.
Sep 13 18:53:32 TimePi sudo[29257]:       pi : TTY=unknown ; PWD=/home/pi ; USER=root ; COMMAND=/usr/sbin/hwclock -r
Sep 13 18:53:32 TimePi sudo[29257]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 13 18:53:33 TimePi dbus-daemon[428]: [system] Activating via systemd: service name='org.freedesktop.timedate1' unit='dbus-org.freedesktop.timedate1.service' requested by ':1.448877' (uid=1000 pid=29261 comm=
Sep 13 18:53:33 TimePi systemd[1]: Starting Time & Date Service...
-- Subject: A start job for unit systemd-timedated.service has begun execution
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- A start job for unit systemd-timedated.service has begun execution.
-- 
-- The job identifier is 13051836.
Sep 13 18:53:33 TimePi dbus-daemon[428]: [system] Successfully activated service 'org.freedesktop.timedate1'
Sep 13 18:53:33 TimePi systemd[1]: Started Time & Date Service.
-- Subject: A start job for unit systemd-timedated.service has finished successfully
-- Defined-By: systemd
-- Support: https://www.debian.org/support
-- 
-- A start job for unit systemd-timedated.service has finished successfully.
-- 
-- The job identifier is 13051836.
Sep 13 18:53:33 TimePi systemd-timedated[29262]: /dev/rtc is busy. Is somebody keeping it open continuously? That's not a good idea... Returning a bogus RTC timestamp.
Sep 13 18:53:33 TimePi sudo[29257]: pam_unix(sudo:session): session closed for user root
pi@TimePi:/etc/mosquitto $ 

Nothing there about MQTT :frowning:
So trying

pi@TimePi:/etc/mosquitto $ sudo systemctl status mosquitto.service 
â—Ź mosquitto.service - Mosquitto MQTT v3.1/v3.1.1 Broker
   Loaded: loaded (/lib/systemd/system/mosquitto.service; enabled; vendor preset: enabled)
   Active: failed (Result: exit-code) since Fri 2024-09-13 18:52:33 AEST; 2min 56s ago
     Docs: man:mosquitto.conf(5)
           man:mosquitto(8)
  Process: 29140 ExecStart=/usr/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf (code=exited, status=3)
 Main PID: 29140 (code=exited, status=3)

Sep 13 18:52:33 TimePi systemd[1]: mosquitto.service: Service RestartSec=100ms expired, scheduling restart.
Sep 13 18:52:33 TimePi systemd[1]: mosquitto.service: Scheduled restart job, restart counter is at 5.
Sep 13 18:52:33 TimePi systemd[1]: Stopped Mosquitto MQTT v3.1/v3.1.1 Broker.
Sep 13 18:52:33 TimePi systemd[1]: mosquitto.service: Start request repeated too quickly.
Sep 13 18:52:33 TimePi systemd[1]: mosquitto.service: Failed with result 'exit-code'.
Sep 13 18:52:33 TimePi systemd[1]: Failed to start Mosquitto MQTT v3.1/v3.1.1 Broker.
pi@TimePi:/etc/mosquitto $ 

If I edit the config file and remark out those two lines, and restart:
It works.
Just to declare.

What does this show?
ls -al /etc/mosquitto/conf.d
and if there are any .conf files in there what is in them?

pi@TimePi:/etc/mosquitto $ ls -al /etc/mosquitto/conf.d/
total 12
drwxr-xr-x 2 root root 4096 Feb 25  2022 .
drwxr-xr-x 5 root root 4096 Sep 13 19:07 ..
-rw-r--r-- 1 root root  142 Nov 17  2019 README
pi@TimePi:/etc/mosquitto $ 

How about
apt policy mosquitto