Mosquitto issue

dastrix80 · October 30, 2018, 8:53pm

Hi All

This has started to happen and a reboot fixes the issue

1540916104: mosquitto version 1.4.15 terminating
1540916104: mosquitto version 1.4.15 (build date Sat, 07 Apr 2018 11:16:43 +0100) starting
1540916104: Config loaded from /etc/mosquitto/mosquitto.conf.
1540916104: Opening ipv4 listen socket on port 1883.
1540916104: Error: Address already in use

I reference localhost in my broker.url, any thoughts as to why suddenly?

Or how I can check which ip’s its got an issue with,


kris@openhab2:/etc/openhab2/services$ cat mqtt.cfg
#
# Define your MQTT broker connections here for use in the MQTT Binding or MQTT
# Persistence bundles. Replace <broker> with an ID you choose.
#

# URL to the MQTT broker, e.g. tcp://localhost:1883 or ssl://localhost:8883
#<broker>.url=tcp://<host>:1883

# Optional. Client id (max 23 chars) to use when connecting to the broker.
# If not provided a random default is generated.
#<broker>.clientId=<clientId>

# Optional. True or false. If set to true, allows the use of clientId values
# up to 65535 characters long. Defaults to false.
# NOTE: clientId values longer than 23 characters may not be supported by all
# MQTT servers. Check the server documentation.
#<broker>.allowLongerClientIds=false

# Optional. User id to authenticate with the broker.
#<broker>.user=<user>

# Optional. Password to authenticate with the broker.
#<broker>.pwd=<password>

# Optional. Set the quality of service level for sending messages to this broker.
# Possible values are 0 (Deliver at most once),1 (Deliver at least once) or 2
# (Deliver exactly once). Defaults to 0.
#<broker>.qos=<qos>

# Optional. True or false. Defines if the broker should retain the messages sent to
# it. Defaults to false.
#<broker>.retain=<retain>

# Optional. True or false. Defines if messages are published asynchronously or
# synchronously. Defaults to true.
#<broker>.async=<async>

# Optional. Defines the last will and testament that is sent when this client goes offline
# Format: topic:message:qos:retained <br/>
#<broker>.lwt=<last will definition>

broker.url=tcp://127.0.0.1:1883
broker.user=mosquitto
broker.pwd=xxx
broker.clientId=openhab

dastrix80 · October 30, 2018, 8:59pm

Bit more info:
Ive made no changes, and installed no software. Just started to occur.


kris@openhab2:/var/log$  sudo systemctl status mosquitto
● mosquitto.service - LSB: mosquitto MQTT v3.1 message broker
   Loaded: loaded (/etc/init.d/mosquitto; generated)
   Active: active (exited) since Wed 2018-10-31 03:15:04 AEDT; 4h 43min ago
     Docs: man:systemd-sysv-generator(8)
  Process: 22734 ExecStop=/etc/init.d/mosquitto stop (code=exited, status=0/SUCCESS)
  Process: 22740 ExecStart=/etc/init.d/mosquitto start (code=exited, status=0/SUCCESS)

Oct 31 03:15:04 openhab2 systemd[1]: Starting LSB: mosquitto MQTT v3.1 message broker...
Oct 31 03:15:04 openhab2 mosquitto[22740]:  * Starting network daemon: mosquitto
Oct 31 03:15:04 openhab2 mosquitto[22740]:    ...done.
Oct 31 03:15:04 openhab2 systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
kris@openhab2:/var/log$

Dim · October 30, 2018, 9:07pm

broker is down

did you recently upgrade mosquitto?

post your /etc/mosquitto/mosquitto.conf

dastrix80 · October 30, 2018, 9:07pm

Hi Angelos, no changes at all


# 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

persistence true
persistence_location /var/lib/mosquitto/

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

include_dir /etc/mosquitto/conf.d

Dim · October 30, 2018, 9:08pm

try adding (at the end):

listener 1883 0.0.0.0

dastrix80 · October 30, 2018, 9:09pm

Can do. Why would it suddenly die?

then just restart it? It works for a few hours and then suddenly stops.

smhaller · October 30, 2018, 9:10pm

Hi Kris
for me this looks as mosquitto is trying to use a port that is already used by another service

1540916104: Error: Address already in use

what is netstat -a | grep 1883 saying?

dastrix80 · October 30, 2018, 9:11pm

Hi Stefan, right now not a great deal!

kris@openhab2:/var/log$ netstat -a | grep 1883
kris@openhab2:/var/log$

Dim · October 30, 2018, 9:13pm

sometimes, this is a misleading message. for example, if the broker is up (active (running)) and you issue mosquitto -v to see the version, you will get the same “error” message.

important is to have the service up (systemctl status mosquitto)

dastrix80 · October 30, 2018, 9:15pm

Tried to start it:

1540876808: New client connected from 192.168.0.237 as gardenlights (c1, k15, u'mosquitto').
1540876810: New connection from 192.168.0.239 on port 1883.
1540876810: New client connected from 192.168.0.239 as DVES_462E34 (c1, k10, u'mosquitto').
1540876811: New connection from 192.168.0.234 on port 1883.
1540876811: New client connected from 192.168.0.234 as DVES_EA4695 (c1, k15, u'mosquitto').
1540876812: New connection from 192.168.0.240 on port 1883.
1540876812: New client connected from 192.168.0.240 as DVES_2D2E43 (c1, k15, u'mosquitto').
1540876866: New connection from 127.0.0.1 on port 1883.
1540876866: New client connected from 127.0.0.1 as openhab (c1, k60, u'mosquitto').
1540878604: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540880405: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540882206: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540884007: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540885808: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540887609: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540889410: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540891211: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540893012: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540894813: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540896614: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540898415: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540900216: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540902017: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540903818: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540905619: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540907420: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540909221: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540911022: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540912823: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540914624: Saving in-memory database to /var/lib/mosquitto/mosquitto.db.
1540916104: mosquitto version 1.4.15 terminating
1540916104: mosquitto version 1.4.15 (build date Sat, 07 Apr 2018 11:16:43 +0100) starting
1540916104: Config loaded from /etc/mosquitto/mosquitto.conf.
1540916104: Opening ipv4 listen socket on port 1883.
1540916104: Error: Address already in use
kris@openhab2:/var/log$


   Loaded: loaded (/etc/init.d/mosquitto; generated)
   Active: active (exited) since Wed 2018-10-31 03:15:04 AEDT; 4h 59min ago
     Docs: man:systemd-sysv-generator(8)
  Process: 22734 ExecStop=/etc/init.d/mosquitto stop (code=exited, status=0/SUCCESS)
  Process: 22740 ExecStart=/etc/init.d/mosquitto start (code=exited, status=0/SUCCESS)

Oct 31 03:15:04 openhab2 systemd[1]: Starting LSB: mosquitto MQTT v3.1 message broker...
Oct 31 03:15:04 openhab2 mosquitto[22740]:  * Starting network daemon: mosquitto
Oct 31 03:15:04 openhab2 mosquitto[22740]:    ...done.
Oct 31 03:15:04 openhab2 systemd[1]: Started LSB: mosquitto MQTT v3.1 message broker.
kris@openhab2:/var/log$

Dim · October 30, 2018, 9:17pm

hmmm

and nothing is using TCP 1883?

lsof -i TCP:1883
netstat | grep 1883

did you add the listener line in the config file?

dastrix80 · October 30, 2018, 9:18pm

Yes sir!


kris@openhab2:/var/log$ lsof -i TCP:1883
kris@openhab2:/var/log$ netstat | grep 1883
kris@openhab2:/var/log$ cat /etc/mosquitto/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

persistence true
persistence_location /var/lib/mosquitto/

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

include_dir /etc/mosquitto/conf.d

listener 1883 0.0.0.0
kris@openhab2:/var/log$

Dim · October 30, 2018, 9:21pm

there is a booked issue for this, but I remember that I solved it some time ago…
I will try to remember what I did

dastrix80 · October 30, 2018, 9:23pm

Hmm. If i restart the server, it works again for a little while…

smhaller · October 30, 2018, 9:25pm

Interesting case, my mq broker is running now for 6 days.

root@orlando:/var/log/mosquitto# systemctl status mosquitto.service
● mosquitto.service - Mosquitto MQTT Broker
Loaded: loaded (/lib/systemd/system/mosquitto.service; enabled; vendor preset: enabled)
Active: active (running) since Wed 2018-10-24 17:36:52 CEST; 6 days ago
Docs: man:mosquitto(8)
https://mosquitto.org/
Main PID: 3815 (mosquitto)
Tasks: 1 (limit: 4915)
CGroup: /system.slice/mosquitto.service
└─3815 /usr/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf

I see only a difference in the calling script, yours are from /etc/init.d while my one is in the /lib/systemd path

dastrix80 · October 30, 2018, 9:26pm

I dont understand why it would change. The only thing thats new on the network is a NAS using a different IP address on a totally different machine, and it doesnt run MQTT/Mosquitto

Dim · October 30, 2018, 9:27pm

I have /etc init also (running it on a laptop with Debian Jessie)

root@homer:/etc/mosquitto# systemctl status mosquitto.service 
● mosquitto.service - LSB: mosquitto MQTT v3.1 message broker
   Loaded: loaded (/etc/init.d/mosquitto)
   Active: active (running) since Tue 2018-10-23 11:12:39 EEST; 1 weeks 0 days ago
   CGroup: /system.slice/mosquitto.service
           └─22272 /usr/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf

Dim · October 30, 2018, 9:29pm

maybe an apt-get upgrade brought you from Mosquitto 1.4 to 1.5 (which has some issues) ?

on which platform are you running it? (rPi with Raspbian Jessie or Stretch?)

dastrix80 · October 30, 2018, 9:30pm

I just did this…


kris@openhab2:/var/log$ mosquitto -v
1540934993: mosquitto version 1.4.15 (build date Sat, 07 Apr 2018 11:16:43 +0100) starting
1540934993: Using default config.
1540934993: Opening ipv4 listen socket on port 1883.
1540934993: Opening ipv6 listen socket on port 1883.
1540934994: New connection from 192.168.0.239 on port 1883.
1540934994: New client connected from 192.168.0.239 as DVES_462E34 (c1, k10, u'mosquitto').
1540934994: Sending CONNACK to DVES_462E34 (0, 0)
1540934994: Received PUBLISH from DVES_462E34 (d0, q0, r1, m0, 'tele/gate/LWT', ... (6 bytes))
1540934994: Received PUBLISH from DVES_462E34 (d0, q0, r0, m0, 'cmnd/gate/POWER', ... (0 bytes))
1540934994: Received SUBSCRIBE from DVES_462E34
1540934994:     cmnd/gate/# (QoS 0)
1540934994: DVES_462E34 0 cmnd/gate/#
1540934994: Sending SUBACK to DVES_462E34
1540934994: Received SUBSCRIBE from DVES_462E34
1540934994:     cmnd/sonoffs/# (QoS 0)
1540934994: DVES_462E34 0 cmnd/sonoffs/#
1540934994: Sending SUBACK to DVES_462E34
1540934994: Received SUBSCRIBE from DVES_462E34
1540934994:     cmnd/DVES_462E34/# (QoS 0)
1540934994: DVES_462E34 0 cmnd/DVES_462E34/#
1540934994: Sending SUBACK to DVES_462E34
1540934995: New connection from 192.168.0.240 on port 1883.
1540934995: New client connected from 192.168.0.240 as DVES_2D2E43 (c1, k15, u'mosquitto').
1540934995: Sending CONNACK to DVES_2D2E43 (0, 0)
1540934995: Received PUBLISH from DVES_2D2E43 (d0, q0, r1, m0, 'tele/gardenbed/LWT', ... (6 bytes))
1540934995: Received PUBLISH from DVES_2D2E43 (d0, q0, r0, m0, 'cmnd/gardenbed/POWER', ... (0 bytes))
1540934995: Received SUBSCRIBE from DVES_2D2E43
1540934995:     cmnd/gardenbed/# (QoS 0)
1540934995: DVES_2D2E43 0 cmnd/gardenbed/#
1540934995: Sending SUBACK to DVES_2D2E43
1540934995: Received SUBSCRIBE from DVES_2D2E43
1540934995:     cmnd/sonoffs/# (QoS 0)
1540934995: DVES_2D2E43 0 cmnd/sonoffs/#
1540934995: Sending SUBACK to DVES_2D2E43
1540934995: Received SUBSCRIBE from DVES_2D2E43
1540934995:     cmnd/DVES_2D2E43/# (QoS 0)
1540934995: DVES_2D2E43 0 cmnd/DVES_2D2E43/#
1540934995: Sending SUBACK to DVES_2D2E43

dastrix80 · October 30, 2018, 9:31pm

im using Ubuntu 18 on Cisco UCS