I forgot to mention something. You could just run sudo run-parts --report /etc/cron.weekly (and cron.daily) to see if the error is reproduced and also what’s going on.
I’ll let you know when I’ve modified the C bits I mentioned yesterday.
EDIT: I just pushed a little change that’ll check for null input at the ACL check and also print what’s getting passed by mosquitto.
Hi @iegomez! Good news! At this version, it appears some interesting messages! Please note that this node is with confirmed data:
//At first, check loragw
DEBU[2018-03-06T14:46:23-03:00] checking acl cache for loragw
DEBU[2018-03-06T14:46:23-03:00] Superuser check with backend Files
DEBU[2018-03-06T14:46:23-03:00] Superuser check with backend Postgres
DEBU[2018-03-06T14:46:23-03:00] Acl check with backend Files
INFO[2018-03-06T14:46:23-03:00] Files acl check with user loragw, topic: gateway/7276ff00080801db/rx, clientid: 7b37cd02-b1af-419a-86e7-6faec934e3cb and acc: 2
INFO[2018-03-06T14:46:23-03:00] Files acl check passed.
DEBU[2018-03-06T14:46:23-03:00] user loragw acl authenticated with backend Files
DEBU[2018-03-06T14:46:23-03:00] setting acl cache (granted = true) for loragw
DEBU[2018-03-06T14:46:23-03:00] Acl is %!s(bool=true) for user loragw
// check do loraserver with acl
printf: acl check for username loraserver, topic gateway/7276ff00080801db/rx, clientid 14f90afd-1f5a-4280-9555-35be2ed91f4b and acc 1
DEBU[2018-03-06T14:46:23-03:00] checking acl cache for loraserver
DEBU[2018-03-06T14:46:23-03:00] Superuser check with backend Files
DEBU[2018-03-06T14:46:23-03:00] Superuser check with backend Postgres
DEBU[2018-03-06T14:46:23-03:00] Acl check with backend Files
INFO[2018-03-06T14:46:23-03:00] Files acl check with user loraserver, topic: gateway/7276ff00080801db/rx, clientid: 14f90afd-1f5a-4280-9555-35be2ed91f4b and acc: 1
INFO[2018-03-06T14:46:23-03:00] Files acl check passed.
DEBU[2018-03-06T14:46:23-03:00] user loraserver acl authenticated with backend Files
DEBU[2018-03-06T14:46:23-03:00] setting acl cache (granted = true) for loraserver
DEBU[2018-03-06T14:46:23-03:00] Acl is %!s(bool=true) for user loraserver
//check lorappserver with node 0004a30b001abe98
printf: acl check for username loraappserver, topic application/1/node/0004a30b001abe98/rx, clientid e84479cb-1169-41f7-b560-8f254d6cfdbc and acc 2
DEBU[2018-03-06T14:46:24-03:00] checking acl cache for loraappserver
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Files
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Postgres
DEBU[2018-03-06T14:46:24-03:00] Acl check with backend Files
INFO[2018-03-06T14:46:24-03:00] Files acl check with user loraappserver, topic: application/1/node/0004a30b001abe98/rx, clientid: e84479cb-1169-41f7-b560-8f254d6cfdbc and acc: 2
INFO[2018-03-06T14:46:23-03:00] Files acl check passed.
DEBU[2018-03-06T14:46:23-03:00] user loraserver acl authenticated with backend Files
DEBU[2018-03-06T14:46:23-03:00] setting acl cache (granted = true) for loraserver
DEBU[2018-03-06T14:46:23-03:00] Acl is %!s(bool=true) for user loraserver
printf: acl check for username loraappserver, topic application/1/node/0004a30b001abe98/rx, clientid e84479cb-1169-41f7-b560-8f254d6cfdbc and acc 2
DEBU[2018-03-06T14:46:24-03:00] checking acl cache for loraappserver
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Files
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Postgres
DEBU[2018-03-06T14:46:24-03:00] Acl check with backend Files
INFO[2018-03-06T14:46:24-03:00] Files acl check with user loraappserver, topic: application/1/node/0004a30b001abe98/rx, clientid: e84479cb-1169-41f7-b560-8f254d6cfdbc and acc: 2
INFO[2018-03-06T14:46:24-03:00] Files acl check passed.
DEBU[2018-03-06T14:46:24-03:00] user loraappserver acl authenticated with backend Files
DEBU[2018-03-06T14:46:24-03:00] setting acl cache (granted = true) for loraappserver
DEBU[2018-03-06T14:46:24-03:00] Acl is %!s(bool=true) for user loraappserver
//check loraappserver ok
warning: received null username, clientid or topic, or access is equal or less than 0 for acl check
warning: received null username, clientid or topic, or access is equal or less than 0 for acl check
warning: received null username, clientid or topic, or access is equal or less than 0 for acl check
warning: received null username, clientid or topic, or access is equal or less than 0 for acl check
warning: received null username, clientid or topic, or access is equal or less than 0 for acl check
warning: received null username, clientid or topic, or access is equal or less than 0 for acl check
warning: received null username, clientid or topic, or access is equal or less than 0 for acl check
warning: received null username, clientid or topic, or access is equal or less than 0 for acl check
warning: received null username, clientid or topic, or access is equal or less than 0 for acl check
warning: received null username, clientid or topic, or access is equal or less than 0 for acl check
printf: acl check for username CPDET, topic application/1/node/0004a30b001abe98/rx, clientid mqtt_7c10e46a.fc20ac and acc 1
DEBU[2018-03-06T14:46:24-03:00] checking acl cache for CPDET
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Files
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Postgres
DEBU[2018-03-06T14:46:24-03:00] Acl check with backend Files
INFO[2018-03-06T14:46:24-03:00] Files acl check with user CPDET, topic: application/1/node/0004a30b001abe98/rx, clientid: mqtt_7c10e46a.fc20ac and acc: 1
WARN[2018-03-06T14:46:24-03:00] Files acl check failed.
DEBU[2018-03-06T14:46:24-03:00] Acl check with backend Postgres
DEBU[2018-03-06T14:46:24-03:00] Checking Postgres for ACL for username CPDET, clientid mqtt_7c10e46a.fc20ac, topic application/1/node/0004a30b001abe98/rx and access 1
DEBU[2018-03-06T14:46:24-03:00] sql query to be executed acc=1 query="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 = $2" username=CPDET
DEBU[2018-03-06T14:46:24-03:00] user CPDET acl authenticated with backend Postgres
DEBU[2018-03-06T14:46:24-03:00] setting acl cache (granted = true) for CPDET
DEBU[2018-03-06T14:46:24-03:00] Acl is %!s(bool=true) for user CPDET
printf: acl check for username det, topic application/1/node/0004a30b001abe98/rx, clientid 8165d083-a2aa-4c92-9fcf-28ba077be05f and acc 1
DEBU[2018-03-06T14:46:24-03:00] checking acl cache for det
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Files
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Postgres
DEBU[2018-03-06T14:46:24-03:00] Acl check with backend Files
INFO[2018-03-06T14:46:24-03:00] Files acl check with user det, topic: application/1/node/0004a30b001abe98/rx, clientid: 8165d083-a2aa-4c92-9fcf-28ba077be05f and acc: 1
WARN[2018-03-06T14:46:24-03:00] Files acl check failed.
DEBU[2018-03-06T14:46:24-03:00] Acl check with backend Postgres
DEBU[2018-03-06T14:46:24-03:00] Checking Postgres for ACL for username det, clientid 8165d083-a2aa-4c92-9fcf-28ba077be05f, topic application/1/node/0004a30b001abe98/rx and access 1
WARN[2018-03-06T14:46:24-03:00] Files acl check failed.
DEBU[2018-03-06T14:46:24-03:00] Acl check with backend Postgres
DEBU[2018-03-06T14:46:24-03:00] Checking Postgres for ACL for username det, clientid 8165d083-a2aa-4c92-9fcf-28ba077be05f, topic application/1/node/0004a30b001abe98/rx and access 1
DEBU[2018-03-06T14:46:24-03:00] sql query to be executed acc=1 query="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 = $2" username=det
DEBU[2018-03-06T14:46:24-03:00] setting acl cache (granted = false) for det
DEBU[2018-03-06T14:46:24-03:00] Acl is %!s(bool=false) for user det
printf: acl check for username loraserver, topic gateway/7276ff00080801db/tx, clientid 14f90afd-1f5a-4280-9555-35be2ed91f4b and acc 2
DEBU[2018-03-06T14:46:24-03:00] checking acl cache for loraserver
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Files
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Postgres
DEBU[2018-03-06T14:46:24-03:00] Acl check with backend Files
INFO[2018-03-06T14:46:24-03:00] Files acl check with user loraserver, topic: gateway/7276ff00080801db/tx, clientid: 14f90afd-1f5a-4280-9555-35be2ed91f4b and acc: 2
INFO[2018-03-06T14:46:24-03:00] Files acl check passed.
DEBU[2018-03-06T14:46:24-03:00] user loraserver acl authenticated with backend Files
DEBU[2018-03-06T14:46:24-03:00] setting acl cache (granted = true) for loraserver
DEBU[2018-03-06T14:46:24-03:00] Acl is %!s(bool=true) for user loraserver
printf: acl check for username loragw, topic gateway/7276ff00080801db/tx, clientid 7b37cd02-b1af-419a-86e7-6faec934e3cb and acc 1
DEBU[2018-03-06T14:46:24-03:00] checking acl cache for loragw
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Files
DEBU[2018-03-06T14:46:24-03:00] Superuser check with backend Postgres
DEBU[2018-03-06T14:46:24-03:00] Acl check with backend Files
INFO[2018-03-06T14:46:24-03:00] Files acl check with user loragw, topic: gateway/7276ff00080801db/tx, clientid: 7b37cd02-b1af-419a-86e7-6faec934e3cb and acc: 1
Whats the difference, please, between acc1 and acc2
The pluging was crashing instead of message
warning: received null username, clientid or topic, or access is equal or less than 0 for acl check
EDIT: It works now with node said before
For ACL checks, mosquitto will pass an access int to the plugin that indicates whether to check for read (subscribe) or write (publish) permissions, where 1 means read and 2 means write.
Well, mosquitto is trying to call the plugin with some null params, which I think should not be allowed by mosquitto, so it may be a bug at their end. I’m guessing that it’s an anonymous user trying to read/write some message, but I thought that with allow_anonymous false mosquitto would discard it previously.
If an anonymous check is indeed the case, I’m happy for now with simply preventing anonymous access from the plugin by denying rights on ACL checks for anonymous users as it’s working now after the modification I did in the morning. That said, if you, @brocaar or anyone else can think of a relevant use case for allowing anonymous access even though the plugin for authentication/authorization is being used, I’ll add support for anonymous users following mosquitto’s original restrictions. I’ll probably add it anyway, but not very soon if it doesn’t seem really urgent/important.
I just pushed some debug messages to identify which string is the one that’s actually null (or if they all are) to get some more info about it and confirm the suspicions. As for now, it will just ignore ACL checks with null params instead of crashing (actually, it’ll return MOSQ_ERR_ACL_DENIED to mosquitto) as you saw in your output.
aWESOME! @iegomez!
I will run this new version. Baybe can you make some option to when the pluging is beeing started mannualy the out is written to some file?
I have tried to point with >> but it had created the file but nothing was written.
Mny thanks !
You can run it like this to redirect all the output to a file when ran manually:
sudo /usr/local/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf > /path/to/manual_mosquitto_log.log 2>&1
Or like this to append to an existing file instead of rewriting it (just change > to >> before the file name):
sudo /usr/local/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf >> /path/to/manual_mosquitto_log.log 2>&1
Hi @iegomez!
In fact ath my side, the commmand above did not worked.
So i ran just mosquitto simlink i guess:
sudo mosquitto -c /etc/mosquitto/mosquitto.conf >>/path/to/manual_mosquitto_log.log 2>&1
Yeah, sorry, that’s just where my mosquitto binary is located.
Hi, @RogerioCassares.
Just wondering, is it working fine now? Do the cron jobs still mess with postgres (did you check running the cron jobs yourself so we don’t have to wait for it to happen)?
Hi @iegomez!
I just comment all cron logs to test and attack the problem in source.
As the problems will being eliminated, we are enabling the cron features.
We decide to make this at that form because it is a way we traced to validated it!
In any cases, i keep you updated to improvements we recognize to be good maybe to implent with the plugin!
Many Thanks!!!
Best Regard!