Restrict MQTT Broker

ChirpStack Application Server
41

Hi @iegomez !

Thats really cool! But in my application i iust want to check when client enter with user and password. No jwt situation. So may I comment JWT for now? It will works just with Files and Postgresqsl ???

Other very important thing is that my user just works on plugin if it is global admin. I woul like it works just if it was only “application admin” not setted as well in “global_admin”.

Maybe this change have to be in queries:

 auth_opt_pg_userquery select password_hash from "user" where username = $1 and is_active = true limit 1
auth_opt_pg_superquery select count(*) from "user" where username = $1 and is_admin = true
auth_opt_pg_aclquery select distinct 'application/' || a.id || '/#' from "user" u inner join organization_user ou on ou.user_id = u.id inner join organization o on o.id = ou.organization_id inner join application a on a.organization_id = o.id where u.username = $1 and $2 = $
42

Yep, you don’t need the JWT backend in that case, just leave files and postgres as the backends options.

Yes again! How postgres authenticates and authorizes depends entirely in the queries that you feed to the plugin, so you may adjust them to your needs. Also, if you don’t need superusers at the postgres end, you may omit the auth_opt_pg_superquery entirely and that backend won’t try to check if a user is superuser (there’s an error on the readme, it says the option is mandatory, but it’s really not).

Hope this works for you! Any other doubt or issue, just let me know. :wink:

EDIT: I fixed the readme, and also relaxed options for JWT backend, which no longer needs jwt_superquery and jwt_aclquery to be mandatory.

43

Hello @iegomez!

Since last message I have kept the pluging working. It was everything ok!
But today as 6:25 am the subscriptions had failed. I know that value because I have a Node-RED application that calculates the last frame log received by the application broker. Even loraserver is working , NEW MESSAGES ARE REGISTRED IN DATABASE (FILES are working!) and I can see it by services status and lora -app-server ui.

So the problem was at the broker connection. As I did not start mannually the mosquitto and to it started i simply reboot the machine, so every connections runs automatically, as they should be.

So I was in logs of mosquitto. In /var/log/mosquitto/mosquitto.log, it has showed the logs with tryng connection to broker but not permited. The users are just the same i have connected yesterday!

1518084318: New connection from 54.191.90.143 on port 1883.
1518084319: Socket error on client <unknown>, disconnecting.

It did not recognized user and simply cant connect.

Otherwise theere was an othe log called /var/mosquitto.log/mosquitto.log.1.gz

In this file, at the final lines, exactly at the time the broker has broken, has the fllowing content:

1518078268: Received PUBLISH from dac1596d-3c88-4657-acf9-cc078e2bd783 (d0, q0, r0, m0, 'gateway/7276ff00080801db/rx', ... (318 bytes))
1518078268: Sending PUBLISH to cc637bdf-a8ea-4a84-ae67-3a5af123540a (d0, q0, r0, m0, 'gateway/7276ff00080801db/rx', ... (318 bytes))
1518078268: Received PUBLISH from 2b64d280-3999-4a72-82eb-55affd05807d (d0, q0, r0, m0, 'application/1/node/0004a30b001abe98/rx', ... (431 bytes))
1518078268: Sending PUBLISH to mqtt_f0caf9a1.e45e08 (d0, q0, r0, m0, 'application/1/node/0004a30b001abe98/rx', ... (431 bytes))
1518078268: Received PUBLISH from cc637bdf-a8ea-4a84-ae67-3a5af123540a (d0, q0, r0, m0, 'gateway/7276ff00080801db/tx', ... (240 bytes))
1518078268: Sending PUBLISH to dac1596d-3c88-4657-acf9-cc078e2bd783 (d0, q0, r0, m0, 'gateway/7276ff00080801db/tx', ... (240 bytes))
1518078293: Received PUBLISH from dac1596d-3c88-4657-acf9-cc078e2bd783 (d0, q0, r0, m0, 'gateway/7276ff00080801db/stats', ... (163 bytes))
1518078293: Sending PUBLISH to cc637bdf-a8ea-4a84-ae67-3a5af123540a (d0, q0, r0, m0, 'gateway/7276ff00080801db/stats', ... (163 bytes))
1518078298: Received PINGREQ from 2b64d280-3999-4a72-82eb-55affd05807d
1518078298: Sending PINGRESP to 2b64d280-3999-4a72-82eb-55affd05807d
1518078298: Received PINGREQ from cc637bdf-a8ea-4a84-ae67-3a5af123540a
1518078298: Sending PINGRESP to cc637bdf-a8ea-4a84-ae67-3a5af123540a
1518078299: Received PINGREQ from dac1596d-3c88-4657-acf9-cc078e2bd783
1518078299: Sending PINGRESP to dac1596d-3c88-4657-acf9-cc078e2bd783
1518078302: Error in poll: Interrupted system call.
1518078302: Reloading config.

I presume when it has Reload config the mosquitto.conf could not read the plugin, so the connection was failed And I cant reestablished anymore. May be this issue fixable?

Thanks in advance!

EDIT: PLEASE NOTE THE TIME 1518078302 IN LAST LINES IS THE TIME OF 6:25am

44

Hi!

Could you please show me the output of systemd’s log at that time instead of /var/log/mosquitto/mosquitto.log? One of these should give you logs from when the problem happened (first one shows logs from yesterday till now, the second one from previous boot):

sudo journalctl -u mosquitto --since yesterday
or
sudo journalctl -u mosquitto -b -1

Also, here’s some info about systemd’s loggin that could be useful: https://www.digitalocean.com/community/tutorials/how-to-use-journalctl-to-view-and-manipulate-systemd-logs

45

Hello sherlock @iegomez …

I could find some lines but I could not realise what the problem is. Executing sudo journalctl i have navigated until the dati time the issue occurs: 6:25 am. Here it is:

     Feb 08 06:24:44 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:24:44-02:00" level=info msg="gateway: received udp packet from gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullData
    Feb 08 06:24:44 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:24:44-02:00" level=info msg="gateway: sending udp packet to gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullACK
    Feb 08 06:24:53 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:24:53-02:00" level=info msg="gateway: received udp packet from gateway" addr=10.193.101.11:44301 protocol_version=2 type=PushData
    Feb 08 06:24:53 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:24:53-02:00" level=info msg="gateway: stat packet received" addr=10.193.101.11:44301 mac=7276ff00080801db
    Feb 08 06:24:53 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:24:53-02:00" level=info msg="backend: publishing packet" topic="gateway/7276ff00080801db/stats"
    Feb 08 06:24:53 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:24:53-02:00" level=info msg="gateway: sending udp packet to gateway" addr=10.193.101.11:44301 protocol_version=2 type=PushACK
    Feb 08 06:24:53 networkserver loraserver[1313]: time="2018-02-08T06:24:53-02:00" level=info msg="backend/gateway: gateway stats packet received" mac=7276ff00080801db
    Feb 08 06:24:53 networkserver loraserver[1313]: time="2018-02-08T06:24:53-02:00" level=info msg="gateway updated" mac=7276ff00080801db
    Feb 08 06:24:55 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:24:55-02:00" level=info msg="gateway: received udp packet from gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullData
    Feb 08 06:24:55 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:24:55-02:00" level=info msg="gateway: sending udp packet to gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullACK
    **Feb 08 06:25:01 networkserver CRON[5904]: pam_unix(cron:session): session opened for user root by (uid=0)**
**    Feb 08 06:25:01 networkserver CRON[5903]: pam_unix(cron:session): session opened for user root by (uid=0)**
**    Feb 08 06:25:01 networkserver CRON[5905]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)**
**    Feb 08 06:25:01 networkserver CRON[5906]: (root) CMD (test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily ))**
**    Feb 08 06:25:01 networkserver CRON[5904]: pam_unix(cron:session): session closed for user root**
**    Feb 08 06:25:02 networkserver systemd[1]: Reloading LSB: Apache2 web server.**
**    Feb 08 06:25:02 networkserver apache2[5948]:  * Reloading Apache httpd web server apache2**
**    Feb 08 06:25:02 networkserver apache2[5948]:  ***
**    Feb 08 06:25:02 networkserver systemd[1]: Reloaded LSB: Apache2 web server.**
**    Feb 08 06:25:05 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:25:05-02:00" level=info msg="gateway: received udp packet from gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullData**
**    Feb 08 06:25:05 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:25:05-02:00" level=info msg="gateway: sending udp packet to gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullACK**
**    Feb 08 06:25:15 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:25:15-02:00" level=info msg="gateway: received udp packet from gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullData**
**    Feb 08 06:25:15 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:25:15-02:00" level=info msg="gateway: sending udp packet to gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullACK**
**    Feb 08 06:25:17 networkserver CRON[5903]: pam_unix(cron:session): session closed for user root**
    Feb 08 06:25:23 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:25:23-02:00" level=info msg="gateway: received udp packet from gateway" addr=10.193.101.11:44301 protocol_version=2 type=PushData
    Feb 08 06:25:23 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:25:23-02:00" level=info msg="gateway: stat packet received" addr=10.193.101.11:44301 mac=7276ff00080801db
    Feb 08 06:25:23 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:25:23-02:00" level=info msg="backend: publishing packet" topic="gateway/7276ff00080801db/stats"
    Feb 08 06:25:23 networkserver lora-gateway-bridge[1274]: time="2018-02-08T06:25:23-02:00" level=info msg="gateway: sending udp packet to gateway" addr=10.193.101.11:44301 protocol_version=2 type=PushACK
    Feb 08 06:25:23 networkserver loraserver[1313]: time="2018-02-08T06:25:23-02:00" level=info msg="backend/gateway: gateway stats packet received" mac=7276ff00080801db
    Feb 08 06:25:23 networkserver loraserver[1313]: time="2018-02-08T06:25:23-02:00" level=info msg="gateway updated" mac=7276ff00080801db

WHat can be happened? :thinking:

46

If you filter by unit mosquitto (using the flag -u, i.e., sudo journalctl -u mosquitto --since yesterday), does it show something?

Also, it shows that cron jobs are getting executed at that time, maybe there’s something going on there.

EDIT: I just reread what you wrote, and if I understand correctly, the loraserver stack continued to work fine (they all went on publishing and subscribing to mqtt messages without problem after the “issue”), but your node-red connection did not. If that is the case, I think the problem has to do with node-red being unable to reconnect to mosquitto if it halts and restarts.

This error just says that when a SIGHUP occurred (for example, for logrotation), mosquitto was calling poll(), so that called failed, and then mosquitto restarted and reloaded the config, as usual:

1518078302: Error in poll: Interrupted system call.
1518078302: Reloading config

For example, in my logs I can see some disconnections from my JS end, but the client is set to reconnect on disconnection, so it just reconnects:

1511446923: Socket error on client test_client, disconnecting.
1511446925: New client connected from 164.77.47.36 as test_client (c1, k3600, ...)
1511446925: Sending CONNACK to test_client (0, 0)
1511446925: Received SUBSCRIBE from test_client

So I’m guessing it’s node-red that doesn’t handle a disconnection correctly.

47

Hi @iegomez

Maybe it is not in node-red. I have made a lot of type of connection to broker default before and when it disconnects, it connect by itself. Also, I have tried to connect mannually and I could not.

sudo journalctl -u mosquitto --since yesterday had as result -- No entries -- . i guess there was not user mosquitto.

I will reboot machine and try reprodice the error

This might be quite usual for mosquitto. That may be not the cause, as you said.

EDIT: The i have done sudo journalctl -u cron --since yesterday and the result is every time it get something. May this in not a problem too

48

Just to be sure, is that right or the loraserver stack stopped being able to pub/sub mqtt messages?

49

Hi @iegomez

All loraserver, lora-app-server and lora-gateway-bridge were all right! The log were comming and correctly at the database. This was registered at ACL and passwords files. But it seems postgres plugin was not working anymore, because when i attempted to connect with user and password it could not.

50

Oh, right. Though it sounds a bit strange, that could be it. Sadly, it seems your systemd logs weren’t persisted for unit mosquitto, maybe because of logrotation, I have to do some digging on that. Could you change the storage option for your journal at /etc/systemd/journald.conf to this just to see if it helps:

[Journal]
Storage=persistent

Hopefully, if it happens again, we’ll get to see the messages about postgres failing to authenticate.

I’ll check about mosquitto’s logrotation and try to reproduce the issue too, and will let you know if I find anything.

1 Like
51

Well @iegomez

I modify as you said and wait if something strange happens!

I have some answers. How the plugn can deal with number of connections? There is a limit of subscriptions ? Have you ever tested before ?

At mosquitto_sub I cant receive anything. I have never received messages with the plugin on The topic is just the same as you wrote many times above but never cant see messagens meanwhile it is cappable to establish the connection as well seen in deugging mode!.

52

There are some quick benchmarks that were ran locally(of course, with no cache) under normal work load and give these results:

BenchmarkFilesUser-4               	      	10 				151611011 ns/op
BenchmarkFilesSuperuser-4           1000000000         			 2.94 ns/op
BenchmarkFilesAcl-4                	  10000000       			  167 ns/op
BenchmarkPostgresUser-4             	      10	 			167902778 ns/op
BenchmarkPostgresSuperser-4         	   10000	   		164956 ns/op
BenchmarkPostgresStrictAcl-4        	   10000	    	202321 ns/op
BenchmarkPostgresSingleLevelAcl-4   	   10000	    	202027 ns/op
BenchmarkPostgresHierarchyAcl-4     	   10000	    	201217 ns/op
BenchmarkRedisUser-4               	      	10	 			152723368 ns/op
BenchmarkRedisSuperuser-4          	  	100000	     			21330 ns/op
BenchmarkRedisStrictAcl-4          	   	 20000	     			84570 ns/op
BenchmarkRedisUserPatternAcl-4     	   	 20000	     			83076 ns/op
BenchmarkRedisClientPatternAcl-4   	   	 20000	     			84883 ns/op
BenchmarkRedisSingleLevelAcl-4     	   	 20000	     			84241 ns/op
BenchmarkRedisHierarchyAcl-4       	   	 20000	     			83835 ns/op

So, in all cases authentication takes about 0,15 seconds. It is very similar on all backends because the bottleneck is hashing the password for comparison, and the hashing speed depends on algorithm and hash iterations, which by default are sha512 and 100000 iterations when pw is built without modifying flags. Luckily, authentication is done once per client (more like once per connection, but you get the idea), so those numbers aren’t troublesome.

As you can see, files superuser and acl checks are really fast, which makes sense because acl records are constructed and stored in Go maps. Redis is a bit faster than Postgres, as Redis runs on memory. So let’s take a look at Postgres.

For user authorization, it takes 0,000164956 seconds per operation, which means it should handle roughly 6062 requests per second. For acls, there’s not much difference between strict, one level wildcard and full wildcard, so for the worst scenario, it takes 0,000202321 seconds per request, or handles nearly 5000 requests per second.

Now, those are just lab prepared benchmarks and probably not very good. Don’ take them too seriously!. I’ve been meaning to use this tool to make better benchmarks with thousands of concurrent connections, but I need to fork and modify it to allow inputing multiple usernames, passwords, clientids, etc., which it doesn’t handle right now (it makes sense, as it is designed to test mqqt brokers, not auth plugins, so it just goes with one username/password for all clients).

1 Like
53

Hi @iegomez

Thanks for the becnmark options!!

That probeme of yesterday morning occurs exactly at same issues at exactly time as before.

As you have said in one of the replies:

These are rhe seults:
sudo journalctl -u mosquitto -b -1
Specifying boot ID has no effect, no persistent journal was found
sudo journalctl -u mosquitto --since yesterday
-- No entries --

You said to save this configuration:

But the results at journalctl are the same. It was at sabme time Apache was restarted by systemd

Feb 09 06:24:41 networkserver lora-app-server[1402]: time="2018-02-09T06:24:41-02:00" level=info msg="data-down item requested by network-server, but queue is empty" dev_eui=0004a30b001a5ea1
Feb 09 06:24:51 networkserver lora-gateway-bridge[1259]: time="2018-02-09T06:24:51-02:00" level=info msg="gateway: received udp packet from gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullData
Feb 09 06:24:51 networkserver lora-gateway-bridge[1259]: time="2018-02-09T06:24:51-02:00" level=info msg="gateway: sending udp packet to gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullACK
Feb 09 06:25:00 networkserver lora-gateway-bridge[1259]: time="2018-02-09T06:25:00-02:00" level=info msg="gateway: received udp packet from gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullData
Feb 09 06:25:00 networkserver lora-gateway-bridge[1259]: time="2018-02-09T06:25:00-02:00" level=info msg="gateway: sending udp packet to gateway" addr=10.193.101.11:33302 protocol_version=2 type=PullACK
Feb 09 06:25:01 networkserver CRON[6963]: pam_unix(cron:session): session opened for user root by (uid=0)
Feb 09 06:25:01 networkserver CRON[6962]: pam_unix(cron:session): session opened for user root by (uid=0)
Feb 09 06:25:01 networkserver CRON[6964]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Feb 09 06:25:01 networkserver CRON[6965]: (root) CMD (test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily ))
Feb 09 06:25:01 networkserver CRON[6963]: pam_unix(cron:session): session closed for user root
Feb 09 06:25:02 networkserver systemd[1]: Reloading LSB: Apache2 web server.
Feb 09 06:25:02 networkserver apache2[7008]:  * Reloading Apache httpd web server apache2
Feb 09 06:25:02 networkserver apache2[7008]:  *
Feb 09 06:25:02 networkserver systemd[1]: Reloaded LSB: Apache2 web server.
Feb 09 06:25:05 networkserver lora-gateway-bridge[1259]: time="2018-02-09T06:25:05-02:00" level=info msg="gateway: received udp packet from gateway" addr=10.193.101.11:44301 protocol_version=2 type=PushData
Feb 09 06:25:05 networkserver lora-gateway-bridge[1259]: time="2018-02-09T06:25:05-02:00" level=info msg="gateway: rxpk packet received" addr=10.193.101.11:44301 data="QFMLHgCAVwBkWsWxsbDHyF2Zxcc=" mac=7276ff00080
Feb 09 06:25:05 networkserver lora-gateway-bridge[1259]: time="2018-02-09T06:25:05-02:00" level=info msg="backend: publishing packet" topic="gateway/7276ff00080801db/rx"
Feb 09 06:25:05 networkserver lora-gateway-bridge[1259]: time="2018-02-09T06:25:05-02:00" level=info msg="gateway: sending udp packet to gateway" addr=10.193.101.11:44301 protocol_version=2 type=PushACK
Feb 09 06:25:05 networkserver loraserver[1311]: time="2018-02-09T06:25:05-02:00" level=info msg="backend/gateway: rx packet received"

As we have seen, the lora server, app server, gw-bridge are work perfectly, but the connection out over the broker, for example, with node-red have been “disconnected” it can not find the broker even to try a connection. It is seems like apache restarted and something more happened that the broker could not be found to connect with postgres plugin.

Here are the error logs of Apache

sudo tail -f /var/log/apache2/error.log

[Fri Feb 09 06:25:02.684841 2018] [mpm_prefork:notice] [pid 1565] AH00163: Apache/2.4.18 (Ubuntu) OpenSSL/1.0.2g configured -- resuming normal operations
[Fri Feb 09 06:25:02.684888 2018] [core:notice] [pid 1565] AH00094: Command line: '/usr/sbin/apache2

Apache is operating well and with no errors!

54

Hi, @RogerioCassares.

After adding the persistent option, did you restart journald? If not, the change was probably not caught and thus it failed to persist mosquitto’s log again. At least that’s what I think happened.
If you did in fact restart journald, then I’ll really have to look into what’s going on with the logs.

Could you share the contents of your crontab? It doesn’t seem to be a coincidence that it fails at the exact same time that it did yesterday.

55

Hello @iegomez!

Here is the sudo nano /etc/systemd/journald.conf

#  This file is part of systemd.
#
#  systemd is free software; you can redistribute it and/or modify it
#  under the terms of the GNU Lesser General Public License as published by
#  the Free Software Foundation; either version 2.1 of the License, or
#  (at your option) any later version.
#
# Entries in this file show the compile time defaults.
# You can change settings by editing this file.
# Defaults can be restored by simply deleting this file.
#
# See journald.conf(5) for details.

[Journal]
Storage=persistent
#Compress=yes
#Seal=yes
#SplitMode=uid
#SyncIntervalSec=5m
#RateLimitInterval=30s
#RateLimitBurst=1000
#SystemMaxUse=
#SystemKeepFree=
#SystemMaxFileSize=
#SystemMaxFiles=100
#RuntimeMaxUse=
#RuntimeKeepFree=
#RuntimeMaxFileSize=
#RuntimeMaxFiles=100
#MaxRetentionSec=
#MaxFileSec=1month
#ForwardToSyslog=yes
#ForwardToKMsg=no
#ForwardToConsole=no
#ForwardToWall=yes
#TTYPath=/dev/console
#MaxLevelStore=debug
#MaxLevelSyslog=debug
#MaxLevelKMsg=notice
#MaxLevelConsole=info
#MaxLevelWall=emerg

I have uncommented the storage as you said and change auto to persistent

I have made now sudo journalctl -u cron and I noticed that a weird wrong log line was logged. THis is only at the time at 6.25.01 am. There was just this line different from standard!

Feb 09 06:17:01 networkserver CRON[6934]: pam_unix(cron:session): session opened for user root by (uid=0)
Feb 09 06:17:01 networkserver CRON[6935]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Feb 09 06:17:01 networkserver CRON[6934]: pam_unix(cron:session): session closed for user root
Feb 09 06:25:01 networkserver CRON[6963]: pam_unix(cron:session): session opened for user root by (uid=0)
Feb 09 06:25:01 networkserver CRON[6962]: pam_unix(cron:session): session opened for user root by (uid=0)
Feb 09 06:25:01 networkserver CRON[6964]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Feb 09 06:25:01 networkserver CRON[6965]: (root) CMD (test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily ))
Feb 09 06:25:01 networkserver CRON[6963]: pam_unix(cron:session): session closed for user root
Feb 09 06:25:16 networkserver CRON[6962]: pam_unix(cron:session): session closed for user root
Feb 09 06:35:01 networkserver CRON[7173]: pam_unix(cron:session): session opened for user root by (uid=0)
Feb 09 06:35:01 networkserver CRON[7174]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Feb 09 06:35:01 networkserver CRON[7173]: pam_unix(cron:session): session closed for user root
Feb 09 06:39:01 networkserver CRON[7255]: pam_unix(cron:session): session opened for user root by (uid=0)
Feb 09 06:39:01 networkserver CRON[7256]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && /usr/lib/php/sessionclean)

Thats the line:
Feb 09 06:25:01 networkserver CRON[6965]: (root) CMD (test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily ))

At /etc/crontab file :

# /etc/crontab: system-wide crontab
# Unlike any other crontab you don't have to run the `crontab'
# command to install the new version when you edit this file
# and files in /etc/cron.d. These files also have username fields,
# that none of the other crontabs do.

SHELL=/bin/sh
PATH=/usr/local/sbin:/usr/local/bin:/sbin:/bin:/usr/sbin:/usr/bin

# m h dom mon dow user  command
17 *    * * *   root    cd / && run-parts --report /etc/cron.hourly
25 6    * * *   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.daily )
47 6    * * 7   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.weekly )
52 6    1 * *   root    test -x /usr/sbin/anacron || ( cd / && run-parts --report /etc/cron.monthly )

At /etc/cron.daily directory there are the scripts:

/apache2  
/apport  
/apt-compat  
/bsdmainutils  
/dpkg  
/logrotate  
/man-db  
/mdadm  
/mlocate  
/passwd 
/popularity-contest  
/sysstat  
/update-notifier-common

Precisesly at apache2:

#!/bin/sh

# run htcacheclean if set to 'cron' mode

set -e
set -u

type htcacheclean > /dev/null 2>&1 || exit 0
[ -e /etc/default/apache-htcacheclean ] || exit 0


# edit /etc/default/apache-htcacheclean to change this
HTCACHECLEAN_MODE=daemon
HTCACHECLEAN_RUN=auto
HTCACHECLEAN_SIZE=300M
HTCACHECLEAN_PATH=/var/cache/apache2/mod_cache_disk
HTCACHECLEAN_OPTIONS=""

. /etc/default/apache-htcacheclean

[ "$HTCACHECLEAN_MODE" = "cron" ] || exit 0

htcacheclean ${HTCACHECLEAN_OPTIONS}    \
                -p${HTCACHECLEAN_PATH}  \
                -l${HTCACHECLEAN_SIZE}

At logrotate:

#!/bin/sh

# Clean non existent log file entries from status file
cd /var/lib/logrotate
test -e status || touch status
head -1 status > status.clean
sed 's/"//g' status | while read logfile date
do
    [ -e "$logfile" ] && echo "\"$logfile\" $date"
done >> status.clean
mv status.clean status

test -x /usr/sbin/logrotate || exit 0
/usr/sbin/logrotate /etc/logrotate.conf
56

By restarting journald, I meant running this:

systemctl restart systemd-journald

Or this:

systemctl reload systemd-journald

The second one tries to reload the configuration so that changes are loaded, though it may fail to do so. The first option just restarts the service. This third options is a mixture of both, trying to reload first and restarting on failure to do so.:

systemctl force-reload systemd-journald

If none of those were executed, then journald didn’t take into account the Storage option modification.

Regarding logs and cron, I don’t know how cleaning Apache’s cache or restarting it could mess with mosquitto. Maybe you could try doing it manually to see if the error is reproduced. Also, try checking the rotated syslogs at /var/log to see if mosquitto appears there.

By the way, what version of mosquitto are you running?

57

hi @iegomez

I will read more detailed your reply now, but yesterday after the changes i have restarted the machine, so changes would be applied, is not?

58

Yeah, they were applied then, so that’s not it. As said, try to check the rotated syslogs and also if manually restarting or cleaning apache’s cache does anything to mosquitto.

On mosquitto version, maybe it has something to do with this issue?

I’m really, really sorry I’m not being of much help, I just can’t reproduce the problem!

59

Hello @iegomez

At first i do not really need apologize yourself, please. This is just a detail. The plugin is great and you just answer greater. Thank you so much for the attention.

Maybe we try to reprduce the error start mosquitto manually.:

  1. Restart The machine: sudo reboot
  2. Change system time to 6:20am: sudo date -s 06:20:00
  3. stop mosquitto: sudo /etc/init.d/mosquitto stop
  4. Kill all the process at por 1883: sudo fuser -k 1883/tcp
  5. Check if there are none: sudo lsof -i :1883
  6. Start mosquitto mannually: sudo mosquitto -c /etc/mosquitto/mosquitto.conf
  7. Set /etc/apache2/apache2.conf : LogLevel error
  8. Wait for the logs at debug window of mosquitto

EDIT: MOSQUITTO VERSION: 3.1

1 Like
60

That’s mqtt version, not the mosquittos broker’s one. Try mosquitto -h to check it (should be the first line, startin with “mosquitto version”).