I have pulled from github since you wrote here. But it could not get yet.
At auth_opt_log_level I try all possibilities to see the difference that were logged. Since have no error and no warnings, it could not show anything. But when i try debug or info the information at mosquitto -c /etc/mosquitto/mosquitto.conf were just the same.
An other really worrisome issue is that when I entered with some subscription or pub, without the password flag or with wrong info from the user or topics, for example, the broker turns to active (exit) and all service stops. So in mosquitto -c /etc/mosquitto/mosquitto.conf show the message of SIGSEGV as before was shown, what didnt occurs on mosquitto with default .conf file.
That error you mean with connection refused on bash occurs when I attempt the second time to connect mosquitto after cancelling first time. The exactly steps I did were try mosquitto_sub -h localhost -u username -t '#' than Ctrl ^ C to stop and did it again. It gives me the Error: Connection refused message. But exactly at this message the mosquitto.service exits.
Do you get a stack trace when SIGSEGV is thrown? Also, did you stop mosquitto service before running it manually, and did you run it with sudo? If you got a stack trace, that could tell us what is crashing. Please stop the mosquitto service and trying running it manually again, then subscribe or publish and paste whatever errors you encounter here.
About the log level, I think mosquitto is masking the pluginâs debug messages because of its own logging level. Please add the following to /etc/mosquitto/mosquitto.conf to allow a more verbose level:
log_type all
And, of course, at /etc/mosquitto/conf.d/your-plugin-file.conf (change to the correct file name):
auth_opt_log_level debug
The only parts where I see a strlen could give a segfault is at functions mosquitto_auth_unpwd_check and mosquitto_auth_unpwd_check, in auth-plugin.c, but that would mean that mosquitto isnât handing some parameters to the plugin, which would be a problem at mosquitto. Function mosquitto_auth_plugin_init could potentially go wrong too when thereâs no value for a key at the configuration file, but it seemed to work fine for you. Anyway, Iâll add some checkings and logging there to see if thereâs indeed a problem when those functions get called. Please check the other stuff I mentioned for now.
EDIT: Mosquitto already handles missing values for option keys, so thatâs no problem. I did modify auth_unpwd_check, checking for null username or password, and fixing the returning error (I was returning an ACL error by mistake). Thatâs been pushed to the repo already, so whith this new version you should see this at the terminal thatâs running mosquitto_sub when username/password pair is wrong:
I have installed the newest version from your last repplies so I got some fix but others not.
When I connect withmosquitto_sub command and there is no authorization at ACLs thats ok, it is working! The mosquitto returns Connection Refused: not authorized many times.
And checking the status of mosquitto.service it is running ok
But when I tried to connect with LoRa-App-Server Global user it returns Connection Refused: not authorized also.
In sudo mosquitto -c /etc/mosquitto/mosquitto.conf there is just INFO [0000] lines. No debug lines has appeared.
i have a Global User mosquitto with password mosquitto
So I try mosquitto_sub -h localhost -t "#" -u mosquitto -P mosquitto and it returns Connection Refused: not authorized
In /var/logs/mosquitto/mosquitto.log it detects the lines
1517932248: Sending CONNACK to 127.0.0.1 (0, 5)
1517932248: Socket error on client <unknown>, disconnecting.
1517932249: New connection from 127.0.0.1 on port 1883.
When I stopped mannualy sudo /etc/init.d/mosquitto stop , then start it again with sudo /etc/init.d/mosquitto start, at /var/logs/mosquitto/mosquitto.logs shows address already in use but it seems to running
1517932429: mosquitto version 1.4.8 (build date Mon, 26 Jun 2017 09:31:02 +0100) starting
1517932429: Config loaded from /etc/mosquitto/mosquitto.conf.
1517932429: Opening ipv4 listen socket on port 1883.
1517932429: Error: Address already in use
Note, please, that even stopping mosquitto the sudo mosquitto -c /etc/mosquitto/mosquitto.conf do not change anything
#POSTGRESQL
auth_opt_pg_host localhost
auth_opt_pg_port 5432
auth_opt_pg_dbname loraserver_as
auth_opt_pg_user loraserver_as
auth_opt_pg_password loraserver_as
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 = $2
#JWT
auth_opt_jwt_remote false
auth_opt_jwt_db postgres
auth_opt_jwt_secret IEGVsUTr1iN1rPRGhu7rCJaQy4TXz6ABc+rh6kdskKQ=
auth_opt_jwt_userquery select count() from âuserâ where username = $1 and is_active = true limit 1
auth_opt_jwt_superquery select count() from âuserâ where username = $1 and is_admin = true
auth_opt_jwt_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 = $2
I will erase mosquitto.logs and send it all here in the next reply.
So I restart the machine and when it init i try mosquitto_sub -h localhost -t "#" -u mosquitto -P mosquitto that returned Connection Refused: not authorised. 5 times.
Here is the /var/logs/mosquitto/mosquitto.logs
1517933583: Sending PINGRESP to b53e4af2-dc35-44af-9f13-7fa75631a751
1517933595: Socket error on client a95b2019-1b26-43f8-879d-847a97b025e3, disconnecting.
1517933595: Received DISCONNECT from 2925b6a1-9e31-494b-923f-4b02ff2a0fd2
1517933595: Client 2925b6a1-9e31-494b-923f-4b02ff2a0fd2 disconnected.
1517933595: Received UNSUBSCRIBE from b53e4af2-dc35-44af-9f13-7fa75631a751
1517933595: gateway/+/rx
1517933595: b53e4af2-dc35-44af-9f13-7fa75631a751 gateway/+/rx
1517933595: Received UNSUBSCRIBE from b53e4af2-dc35-44af-9f13-7fa75631a751
1517933595: gateway/+/stats
1517933595: b53e4af2-dc35-44af-9f13-7fa75631a751 gateway/+/stats
1517933595: Socket error on client b53e4af2-dc35-44af-9f13-7fa75631a751, disconnecting.
1517933598: mosquitto version 1.4.8 terminating
1517933635: mosquitto version 1.4.8 (build date Mon, 26 Jun 2017 09:31:02 +0100) starting
1517933635: Config loaded from /etc/mosquitto/mosquitto.conf.
1517933638: Opening ipv4 listen socket on port 1883.
1517933638: Opening ipv6 listen socket on port 1883.
1517933643: New connection from 127.0.0.1 on port 1883.
1517933643: New client connected from 127.0.0.1 as 506fcff6-0b5e-402b-8731-5b9d085e9dee (c1, k30, u'loraserver').
1517933643: Sending CONNACK to 506fcff6-0b5e-402b-8731-5b9d085e9dee (0, 0)
1517933643: New connection from 127.0.0.1 on port 1883.
1517933643: New client connected from 127.0.0.1 as 5e4c8be0-4130-4cb3-92bd-c013f8c37ea1 (c1, k30, u'loragw').
1517933643: Sending CONNACK to 5e4c8be0-4130-4cb3-92bd-c013f8c37ea1 (0, 0)
1517933643: Received SUBSCRIBE from 506fcff6-0b5e-402b-8731-5b9d085e9dee
1517933643: gateway/+/rx (QoS 2)
1517933643: 506fcff6-0b5e-402b-8731-5b9d085e9dee 2 gateway/+/rx
1517933643: Sending SUBACK to 506fcff6-0b5e-402b-8731-5b9d085e9dee
1517933643: Received SUBSCRIBE from 506fcff6-0b5e-402b-8731-5b9d085e9dee
1517933643: gateway/+/stats (QoS 2)
1517933643: 506fcff6-0b5e-402b-8731-5b9d085e9dee 2 gateway/+/stats
1517933643: Sending SUBACK to 506fcff6-0b5e-402b-8731-5b9d085e9dee
1517933644: New connection from 127.0.0.1 on port 1883.
1517933644: New client connected from 127.0.0.1 as 69b828a1-1cfa-49f6-a5f0-a17cf3c5e49d (c1, k30, u'loraappserver').
1517933644: Sending CONNACK to 69b828a1-1cfa-49f6-a5f0-a17cf3c5e49d (0, 0)
1517933644: Received SUBSCRIBE from 69b828a1-1cfa-49f6-a5f0-a17cf3c5e49d
1517933644: application/+/node/+/tx (QoS 2)
1517933644: 69b828a1-1cfa-49f6-a5f0-a17cf3c5e49d 2 application/+/node/+/tx
1517933644: Sending SUBACK to 69b828a1-1cfa-49f6-a5f0-a17cf3c5e49d
1517933673: Received PINGREQ from 5e4c8be0-4130-4cb3-92bd-c013f8c37ea1
1517933673: Sending PINGRESP to 5e4c8be0-4130-4cb3-92bd-c013f8c37ea1
1517933673: Received PINGREQ from 506fcff6-0b5e-402b-8731-5b9d085e9dee
1517933673: Sending PINGRESP to 506fcff6-0b5e-402b-8731-5b9d085e9dee
1517933674: Received PINGREQ from 69b828a1-1cfa-49f6-a5f0-a17cf3c5e49d
1517933674: Sending PINGRESP to 69b828a1-1cfa-49f6-a5f0-a17cf3c5e49d
1517933701: New connection from 127.0.0.1 on port 1883.
1517933701: Sending CONNACK to 127.0.0.1 (0, 5)
1517933701: Socket error on client <unknown>, disconnecting.
1517933702: New connection from 127.0.0.1 on port 1883.
1517933702: Sending CONNACK to 127.0.0.1 (0, 5)
1517933702: Socket error on client <unknown>, disconnecting.
1517933703: New connection from 127.0.0.1 on port 1883.
1517933703: Sending CONNACK to 127.0.0.1 (0, 5)
1517933703: Socket error on client <unknown>, disconnecting.
1517933703: Received PINGREQ from 5e4c8be0-4130-4cb3-92bd-c013f8c37ea1
1517933703: Sending PINGRESP to 5e4c8be0-4130-4cb3-92bd-c013f8c37ea1
1517933703: Received PINGREQ from 506fcff6-0b5e-402b-8731-5b9d085e9dee
1517933703: Sending PINGRESP to 506fcff6-0b5e-402b-8731-5b9d085e9dee
1517933704: New connection from 127.0.0.1 on port 1883.
1517933704: Sending CONNACK to 127.0.0.1 (0, 5)
1517933704: Socket error on client <unknown>, disconnecting.
1517933704: Received PINGREQ from 69b828a1-1cfa-49f6-a5f0-a17cf3c5e49d
1517933704: Sending PINGRESP to 69b828a1-1cfa-49f6-a5f0-a17cf3c5e49d
1517933705: New connection from 127.0.0.1 on port 1883.
1517933705: Sending CONNACK to 127.0.0.1 (0, 5)
1517933705: Socket error on client <unknown>, disconnecting.
1517933733: Received PINGREQ from 5e4c8be0-4130-4cb3-92bd-c013f8c37ea1
1517933733: Sending PINGRESP to 5e4c8be0-4130-4cb3-92bd-c013f8c37ea1
1517933733: Received PINGREQ from 506fcff6-0b5e-402b-8731-5b9d085e9dee
1517933733: Sending PINGRESP to 506fcff6-0b5e-402b-8731-5b9d085e9dee
1517933734: Received PINGREQ from 69b828a1-1cfa-49f6-a5f0-a17cf3c5e49d
1517933734: Sending PINGRESP to 69b828a1-1cfa-49f6-a5f0-a17cf3c5e49d
1517933763: Received PINGREQ from 5e4c8be0-4130-4cb3-92bd-c013f8c37ea1
Here is the sudo mosquitto -c /etc/mosquitto/mosquitto.conf result
INFO[0000] Got 4 users from passwords file.
INFO[0000] created aclrecord {gateway/+/stats 2} for user loragw
INFO[0000] created aclrecord {gateway/+/rx 2} for user loragw
INFO[0000] created aclrecord {gateway/+/tx 1} for user loragw
INFO[0000] created aclrecord {gateway/+/stats 1} for user loraserver
INFO[0000] created aclrecord {gateway/+/tx 2} for user loraserver
INFO[0000] created aclrecord {gateway/+/rx 1} for user loraserver
INFO[0000] created aclrecord {application/+/node/+/rx 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/join 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/ack 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/error 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/tx 1} for user loraappserver
INFO[0000] Got 11 lines from acl file.
INFO[0000] Backend registered: Files
INFO[0000] Backend registered: Postgres
INFO[0000] Backend registered: JWT
INFO[0000] Cache activated
INFO[0000] started cache redis client
Iâm not sure if it makes a difference, but I have the mosquitto log level set at /etc/mosquitto/mosquitto.conf, not at the plugin conf. Hereâs an example of my file:
Was it that then? It prints debug level messages now? Sadly, mosquittoâs man page doesnât seem to mention this, or at least it is not clear:
include_dir dir
External configuration files may be included by using the include_dir option. This defines a directory that will be searched for config files. All files that end in â.confâ will be loaded as a configuration file. It is best to have this as the last option in the main file. This option will only be processed from the main configuration file. The directory specified must not contain the main configuration file.
If the architecture is the same, it probably should. I just tried copying my locally compiled go-auth.so (on a Linux Mint 18 machine) file to my remote server (an Ubuntu 17.04 Linode instance) and it worked fine, but I donât know if the underlying runtime that gets built with cgo wonât find a problem regarding versions. Guess youâll have to try, sorry for the uncertainty.
It depends on how the user will get authenticated and authorized. For example, if you tried to subscribe using mosquitto_sub with loragw user, then yes, the ACLs file will determine which topics are allowed for the user. In this case, loragw should be able to see messages from topics following the gateway/+/tx pattern, so gateway/1/tx and gateway/2/tx should allow read access, but gateway/1/wrong/level/tx should not.
On the other hand, for a lora-app-server user, such as the default admin one, Postgres backend queries will apply for ACL. Similarly, if you use a javascript client to get a live feed of messages and connect using your userâs jwt token as username, the JWT backend will authenticate the user and then restrict topic access using the jwt queries that you configured.
No, itâs not necessary at all, itâs just a regular mosquitto ACLs option, so itâs there it to be fully compatible. What it does is restrict access based on the username or clientid given in the pub/sub topic, so for example with this ACLs:
pattern read test/%u
pattern read test/%c
A user with username my_username should be able to subscribe to topic test/my_username, and a user with clientid my_client_id should be able to subscribe to topic test/my_client_id.
I can also see that the .conf file does his role as well by permissioning just the users to get access to the topics. But the issue is that even I am subscribed, the payload arrives to the server (i can get the confirmation on my node and see the databaseâs frame_log table).
But this data is not being read by user. So I stay connected but nothing arrives at my subscription even I knowing that data is comming .
Before answering, I just caught that you have a couple of typos at your conf for the JWT backend:
In both cases you should have count(*) or count(id), not count().
Now, letâs check some things:
ÂżWith which user and to which topic are you subscribing? ÂżAre you positive that it gets authenticated for the user/password pair?
When correctly connected through mosquitto_sub and authenticated, whenever mosquitto receives a topic matching the subscription, the plugin should log (in debug level) any authorization (acls, basically) requests from connected users, so you should see logs entries where the plugin first checks if thereâs an acl cache record for that user and topic, then checks if the user is a superuser and finally checks for normal authorization against backends until one authorizes the user or none do, in which case the subscription gets rejected. So, you should follow these steps to check if everything is working fine:
Disconnect the user by stopping mosquitto_sub and wait a minute so the cache records get deleted.
Stop mosquitto service or manual instance if you did it hat way.
Start mosquitto manually as seen in other replies.
On a different terminal, subscribe to the correct topic with a user that should be authorized:
Check in the mosquitto terminal for a message that states the user was indeed authenticated. For example, something like this:
level=debug msg="user my_user authenticated with backend Postgres\n"
If you donât see this, it means that the user wasnât authenticated.
Now, when a message gets sent to mosquitto for which you subscribed, you should see messages showing the authorization process. For a superuser case (example, âadminâ), something like this could get logged:
DEBU[0164] superuser admin acl authenticated with backend Postgres
DEBU[0164] setting acl cache (granted = true) for admin
DEBU[0164] Acl is %!s(bool=true) for user admin
If, instead, the user isnât authorized to read that topic, youâll get something like this:
DEBU[0363] checking acl cache for iegomez
DEBU[0363] Superuser check with backend Files
DEBU[0363] Superuser check with backend Postgres
DEBU[0363] Superuser check with backend JWT
DEBU[0363] jwt parse error: token contains an invalid number of segments
DEBU[0363] jwt get superuser error: token contains an invalid number of segments
DEBU[0363] Superuser check with backend Redis
DEBU[0363] Redis get superuser error: redis: nil
DEBU[0363] Acl check with backend Files
INFO[0363] Files acl check with user iegomez, topic: gateway/b827ebfffee100b5/rx, clientid: mosqsub|5096-iegomez-X4 and acc: 1
WARN[0363] Files acl check failed.
DEBU[0363] Acl check with backend Postgres
DEBU[0363] Acl check with backend JWT
DEBU[0363] jwt parse error: token contains an invalid number of segments
DEBU[0363] jwt check acl error: token contains an invalid number of segments
DEBU[0363] Acl check with backend Redis
DEBU[0363] setting acl cache (granted = false) for iegomez
DEBU[0363] Acl is %!s(bool=false) for user iegomez
Now, take in consideration that if for example loraserver isnât running, you wonât see messages from topics like âapplication/id/#â, but you could inspect those that are sent by the lora-gateway-bridge if that was running. Furthermore, as the user admin is a superuser, you should be able to subscribe to a general wildcard, so messages following the patter âgateway/gwMac/rxâ should be visible when doing this:
Ok, all of that said, could you try this process to see what you get? Reply with any relevant information that you see in the output of the mosquitto terminal to debug whatever problem may arise.
I have detaild read and detailed as info as i could to reply your reply from my reply from yours from mine âŚ
This was a format issue of the editor, params_between_**_stays_in_itallic
I am subscribing with username/password mosquitto/mosquitto at topic "#". These can be authenticated meanwhile they are superusers in the server database.
The plugin installed is not debuging at any case!
sudo mosquitto -c /etc/mosquitto/mosquitto.conf
INFO[0000] Got 4 users from passwords file.
INFO[0000] created aclrecord {gateway/+/stats 2} for user loragw
INFO[0000] created aclrecord {gateway/+/rx 2} for user loragw
INFO[0000] created aclrecord {gateway/+/tx 1} for user loragw
INFO[0000] created aclrecord {gateway/+/stats 1} for user loraserver
INFO[0000] created aclrecord {gateway/+/tx 2} for user loraserver
INFO[0000] created aclrecord {gateway/+/rx 1} for user loraserver
INFO[0000] created aclrecord {application/+/node/+/rx 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/join 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/ack 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/error 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/tx 1} for user loraappserver
INFO[0000] Got 11 lines from acl file.
INFO[0000] Backend registered: Files
INFO[0000] Backend registered: Postgres
INFO[0000] Backend registered: JWT
INFO[0000] Cache activated
INFO[0000] started cache redis client
It just appears at /var/log/mosquitto/mosquitto.log
1518016530: New client connected from 127.0.0.1 as mosqsub/2893-roger-Insp (c1, k60, u'mosquitto').
1518016530: Sending CONNACK to mosqsub/2893-roger-Insp (0, 0)
1518016530: Received SUBSCRIBE from mosqsub/2893-roger-Insp
1518016530: # (QoS 0)
1518016530: mosqsub/2893-roger-Insp 0 #
1518016530: Sending SUBACK to mosqsub/2893-roger-Insp
1518016533: Socket error on client mosqsub/2893-roger-Insp, disconnecting.
Ok! Ctrl^C at mosquitto_sub CLI and waited
Ok! sudo /etc/init.d/mosquitto stop
Ok! sudo /etc/init.d/mosquitto start
/var/log/mosquitto/mosquitto.log
1518017617: mosquitto version 1.4.8 (build date Mon, 26 Jun 2017 09:31:02 +0100) starting
1518017617: Config loaded from /etc/mosquitto/mosquitto.conf.
1518017617: Opening ipv4 listen socket on port 1883.
1518017617: Error: Address already in use
nothing was received in mosquitto_sub terminal. Even this message could not seen in anywhere.
Again, no lines of [DEBU] appears at sudo mosquitto -c /etc/mosquitto/mosquitto.conf :?
LoRa Server, app and gateway bridge are workin and they can connect to mosquitto over ACLs file. I can check it in status of each service and at mosquitto.log
The data is not arriving at mosquitto_sub.
I have also subscribed at topic application/+/node/+/rx, as we can see in mosquitto.logs also but nothing we can see at sudo mosquitto -c /etc/mosquitto/mosquitto.conf
1518018942: New connection from 127.0.0.1 on port 1883.
1518018943: New client connected from 127.0.0.1 as mosqsub/4128-roger-Insp (c1, k60, u'mosquitto').
1518018943: Sending CONNACK to mosqsub/4128-roger-Insp (0, 0)
1518018943: Received SUBSCRIBE from mosqsub/4128-roger-Insp
1518018943: application/+/node/+/rx (QoS 0)
1518018943: mosqsub/4128-roger-Insp 0 application/+/node/+/rx
1518018943: Sending SUBACK to mosqsub/4128-roger-Insp
1518018944: Received PINGREQ from 5d158b2d-3053-4977-9116-e9b4e63940b2
Why topic is with /device/ and not with /node/ in this line?
By manually I mean with sudo mosquitto -c /etc/mosquitto/mosquitto.conf, but having the mosquitto service stopped before. What you wrote, sudo /etc/init.d/mosquitto start, will start the service and then you wonât be able to run it correctly from a terminal. In fact, it will try to run and get to these lines and then exit, as it canât get ahold of the port:
As you can see in that log, you already have a process running at port 1883. I strongly suspect that in fact you have the mosquitto service running from before, which is not getting the log level configurations that you need because it hasnât updated itâs conf. Moreover, /var/log/mosquitto/mosquitto.log wonât log the information that we are looking for, it would be seen by running sudo journalctl -u mosquitto -f -n 50 if the service was started with user mosquitto (as is usually done by systemd or init.d).
To summarize, you need to stop the service (sudo service mosquitto stop), make sure that thereâs no instance of mosquitto running. You can check in various ways, these commands should check status of the service, that thereâs no process called mosquitto running and that port 1883 isnât being used:
sudo service mosquitto status (to check mosquitto status)
sudo ps -A | grep -i mosquitto (to check process names)
sudo lsof -i :1883 (to check if some process is using port 1883)
After you are sure that none of those show that mosquitto is running, run it manually from a terminal with sudo /usr/local/sbin/mosquitto -c /etc/mosquitto/mosquitto.conf or sudo mosquitto -c /etc/mosquitto/mosquitto.conf to be able to see everything thatâs going on live. The program shouldnât finish after the final lines that youâve been getting.
At least in latest loraserver and lora-app-server versions, topics use device, not node. Anyway, subscribe to â#â with a superuser, such as admin/admin from lora-app-server, nd be sure that something is being published to the broker to really check that everything is going ok after the previous steps.
Now I can get it! The problem was I was starting mosquitto but the ports were in use by lora services and my system on IPv4 and IPv6. PLease Check it out!
So I stop all process with sudo fuser -k 1883/tcp command, that kill all process at port 1883.
Then I have checked again with sudo lsof -i :1883. The resul was none.
Ok! Nooow with every process at port 1883 stoped i can execute sudo mosquitto -c /etc/mosquitto/mosquitto.conf
In the result, the DEBU[0012] HAS APPEAR!
INFO[0000] Got 4 users from passwords file.
INFO[0000] created aclrecord {gateway/+/stats 2} for user loragw
INFO[0000] created aclrecord {gateway/+/rx 2} for user loragw
INFO[0000] created aclrecord {gateway/+/tx 1} for user loragw
INFO[0000] created aclrecord {gateway/+/stats 1} for user loraserver
INFO[0000] created aclrecord {gateway/+/tx 2} for user loraserver
INFO[0000] created aclrecord {gateway/+/rx 1} for user loraserver
INFO[0000] created aclrecord {application/+/node/+/rx 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/join 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/ack 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/error 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/tx 1} for user loraappserver
INFO[0000] Got 11 lines from acl file.
INFO[0000] Backend registered: Files
INFO[0000] Backend registered: Postgres
INFO[0000] Backend registered: JWT
INFO[0000] Cache activated
INFO[0000] started cache redis client
DEBU[0012] checking auth cache for mosquitto
DEBU[0012] checking user mosquitto with backend Files
DEBU[0012] checking user mosquitto with backend Postgres
DEBU[0012] user mosquitto authenticated with backend Postgres
DEBU[0012] setting auth cache for mosquitto
After that, I execute in other terminal the command sudo lsof -i :1883. Initiating Mmosquitto mannually as you said.
At /var/log/mosquitto/mosquitto.log it did not shows
When it was started
1518026129: mosquitto version 1.4.8 (build date Mon, 26 Jun 2017 09:31:02 +0100) starting
1518026129: Config loaded from /etc/mosquitto/mosquitto.conf.
1518026129: Opening ipv4 listen socket on port 1883.
1518026129: Opening ipv6 listen socket on port 1883.
1518026129: Opening websockets listen socket on port 1884.
1518026141: New connection from 10.97.97.100 on port 1883.
1518026141: New client connected from 10.97.97.100 as mqtt_3456c138.f687ee (c1, k60, u'mosquitto').
1518026141: Sending CONNACK to mqtt_3456c138.f687ee (0, 0)
1518026141: Received SUBSCRIBE from mqtt_3456c138.f687ee
1518026141: application/+/node/0004a30b001e8b8e/rx (QoS 2)
1518026141: mqtt_3456c138.f687ee 2 application/+/node/0004a30b001e8b8e/rx
1518026141: Sending SUBACK to mqtt_3456c138.f687ee
1518026201: Received PINGREQ from mqtt_3456c138.f687ee
1518026201: Sending PINGRESP to mqtt_3456c138.f687ee
1518026261: Received PINGREQ from mqtt_3456c138.f687ee
1518026261: Sending PINGRESP to mqtt_3456c138.f687ee
OKKK!!! I GUESS WE ARE ALMOSSSTTT!!! IT IS SO EXCITING!
Here when I start mannually:
INFO[0000] Got 4 users from passwords file.
INFO[0000] created aclrecord {gateway/+/stats 2} for user loragw
INFO[0000] created aclrecord {gateway/+/rx 2} for user loragw
INFO[0000] created aclrecord {gateway/+/tx 1} for user loragw
INFO[0000] created aclrecord {gateway/+/stats 1} for user loraserver
INFO[0000] created aclrecord {gateway/+/tx 2} for user loraserver
INFO[0000] created aclrecord {gateway/+/rx 1} for user loraserver
INFO[0000] created aclrecord {application/+/node/+/rx 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/join 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/ack 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/error 2} for user loraappserver
INFO[0000] created aclrecord {application/+/node/+/tx 1} for user loraappserver
INFO[0000] Got 11 lines from acl file.
INFO[0000] Backend registered: Files
INFO[0000] Backend registered: Postgres
INFO[0000] Backend registered: JWT
INFO[0000] Cache activated
INFO[0000] started cache redis client
DEBU[0001] checking auth cache for loragw
DEBU[0001] checking user loragw with backend Files
DEBU[0001] user loragw authenticated with backend Files
DEBU[0001] setting auth cache for loragw
DEBU[0006] checking acl cache for loragw
DEBU[0006] Superuser check with backend Files
DEBU[0006] Superuser check with backend Postgres
DEBU[0006] Superuser check with backend JWT
DEBU[0006] jwt parse error: token contains an invalid number of segments
DEBU[0006] jwt get superuser error: token contains an invalid number of segments
DEBU[0006] Acl check with backend Files
INFO[0006] Files acl check with user loragw, topic: gateway/7276ff00080801db/stats, clientid: a45007a8-ea3a-4117-bc7f-c18728fba235 and acc: 2
INFO[0006] Files acl check passed.
DEBU[0006] user loragw acl authenticated with backend Files
DEBU[0006] setting acl cache (granted = true) for loragw
DEBU[0006] Acl is %!s(bool=true) for user loragw
DEBU[0010] checking auth cache for mosquitto
DEBU[0010] checking user mosquitto with backend Files
DEBU[0010] checking user mosquitto with backend Postgres
DEBU[0011] user mosquitto authenticated with backend Postgres
DEBU[0011] setting auth cache for mosquitto
DEBU[0021] checking acl cache for loragw
DEBU[0021] Superuser check with backend Files
DEBU[0021] Superuser check with backend Postgres
DEBU[0021] Superuser check with backend JWT
DEBU[0021] jwt parse error: token contains an invalid number of segments
DEBU[0021] jwt get superuser error: token contains an invalid number of segments
DEBU[0021] Acl check with backend Files
INFO[0021] Files acl check with user loragw, topic: gateway/7276ff00080801db/rx, clientid: a45007a8-ea3a-4117-bc7f-c18728fba235 and acc: 2
INFO[0021] Files acl check passed.
DEBU[0021] user loragw acl authenticated with backend Files
DEBU[0021] setting acl cache (granted = true) for loragw
DEBU[0021] Acl is %!s(bool=true) for user loragw
DEBU[0036] checking acl cache for loragw
DEBU[0036] found in cache: loragw
DEBU[0066] checking acl cache for loragw
DEBU[0066] found in cache: loragw
DEBU[0071] checking auth cache for mosquitto
DEBU[0071] checking user mosquitto with backend Files
DEBU[0071] checking user mosquitto with backend Postgres
DEBU[0072] user mosquitto authenticated with backend Postgres
DEBU[0072] setting auth cache for mosquitto
DEBU[0090] checking auth cache for mosquitto
DEBU[0090] checking user mosquitto with backend Files
DEBU[0090] checking user mosquitto with backend Postgres
DEBU[0090] checking user mosquitto with backend JWT
DEBU[0090] jwt parse error: token contains an invalid number of segments
INFO[0090] jwt get user error: token contains an invalid number of segments
DEBU[0090] setting auth cache for mosquitto
DEBU[0091] checking auth cache for mosquitto
DEBU[0091] found in cache: mosquitto
DEBU[0092] checking auth cache for mosquitto
DEBU[0092] found in cache: mosquitto
DEBU[0093] checking auth cache for mosquitto
DEBU[0093] found in cache: mosquitto
DEBU[0094] checking auth cache for mosquitto
DEBU[0094] found in cache: mosquitto
DEBU[0095] checking auth cache for mosquitto
DEBU[0095] found in cache: mosquitto
DEBU[0096] checking acl cache for loragw
DEBU[0096] Superuser check with backend Files
DEBU[0096] Superuser check with backend Postgres
DEBU[0096] Superuser check with backend JWT
DEBU[0096] jwt parse error: token contains an invalid number of segments
DEBU[0096] jwt get superuser error: token contains an invalid number of segments
DEBU[0096] Acl check with backend Files
INFO[0096] Files acl check with user loragw, topic: gateway/7276ff00080801db/stats, clientid: a45007a8-ea3a-4117-bc7f-c18728fba235 and acc: 2
INFO[0096] Files acl check passed.
DEBU[0096] user loragw acl authenticated with backend Files
DEBU[0096] setting acl cache (granted = true) for loragw
DEBU[0096] Acl is %!s(bool=true) for user loragw
DEBU[0096] checking auth cache for mosquitto
DEBU[0096] found in cache: mosquitto
DEBU[0097] checking auth cache for mosquitto
DEBU[0097] found in cache: mosquitto
DEBU[0098] checking auth cache for mosquitto
DEBU[0098] found in cache: mosquitto
DEBU[0099] checking auth cache for mosquitto
DEBU[0099] found in cache: mosquitto
DEBU[0100] checking auth cache for mosquitto
DEBU[0100] found in cache: mosquitto
DEBU[0101] checking auth cache for mosquitto
DEBU[0101] found in cache: mosquitto
DEBU[0110] checking auth cache for mosquitto
DEBU[0110] checking user mosquitto with backend Files
DEBU[0110] checking user mosquitto with backend Postgres
DEBU[0110] user mosquitto authenticated with backend Postgres
DEBU[0110] setting auth cache for mosquitto
DEBU[0110] checking acl cache for loragw
DEBU[0110] Superuser check with backend Files
DEBU[0110] Superuser check with backend Postgres
DEBU[0110] Superuser check with backend JWT
DEBU[0110] jwt parse error: token contains an invalid number of segments
DEBU[0110] jwt get superuser error: token contains an invalid number of segments
DEBU[0110] Acl check with backend Files
INFO[0110] Files acl check with user loragw, topic: gateway/7276ff00080801db/rx, clientid: a45007a8-ea3a-4117-bc7f-c18728fba235 and acc: 2
INFO[0110] Files acl check passed.
DEBU[0110] user loragw acl authenticated with backend Files
DEBU[0110] setting acl cache (granted = true) for loragw
DEBU[0110] Acl is %!s(bool=true) for user loragw
DEBU[0126] checking acl cache for loragw
DEBU[0126] found in cache: loragw
DEBU[0156] checking acl cache for loragw
DEBU[0156] Superuser check with backend Files
DEBU[0156] Superuser check with backend Postgres
DEBU[0156] Superuser check with backend JWT
DEBU[0156] jwt parse error: token contains an invalid number of segments
DEBU[0156] jwt get superuser error: token contains an invalid number of segments
DEBU[0156] Acl check with backend Files
INFO[0156] Files acl check with user loragw, topic: gateway/7276ff00080801db/stats, clientid: a45007a8-ea3a-4117-bc7f-c18728fba235 and acc: 2
INFO[0156] Files acl check passed.
DEBU[0156] user loragw acl authenticated with backend Files
DEBU[0156] setting acl cache (granted = true) for loragw
DEBU[0156] Acl is %!s(bool=true) for user loragw
DEBU[0186] checking acl cache for loragw
DEBU[0186] found in cache: loragw
DEBU[0216] checking acl cache for loragw
DEBU[0216] Superuser check with backend Files
DEBU[0216] Superuser check with backend Postgres
DEBU[0216] Superuser check with backend JWT
DEBU[0216] jwt parse error: token contains an invalid number of segments
DEBU[0216] jwt get superuser error: token contains an invalid number of segments
DEBU[0216] Acl check with backend Files
INFO[0216] Files acl check with user loragw, topic: gateway/7276ff00080801db/stats, clientid: a45007a8-ea3a-4117-bc7f-c18728fba235 and acc: 2
INFO[0216] Files acl check passed.
DEBU[0216] user loragw acl authenticated with backend Files
DEBU[0216] setting acl cache (granted = true) for loragw
DEBU[0216] Acl is %!s(bool=true) for user loragw
SO I got an error with segments with JWT_token. I just copied it from /etc/defaults/lora-app-server in JWT_SECRET field. It is in base64 in both cases.
# JWT secret used for api authentication / authorization
# You could generate this by executing 'openssl rand -base64 32' for example
JWT_SECRET=IEGVsUTr1iN1rPRGhu7rCJaQy4TXz6ABc+rh6kdskKQ=
When you get these debug âerrorsâ it doesnât mean that thereâs an error with the plugin, at least not necessarily. You see, the plugin will try to authenticate or authorize each user with every plugin until either one plugin correctly authenticates/authorizes the user, or no plugin returned ok (so auth fails for the user). Moreover, a user may be checked against a plugin that wonât be able to authenticate him before reaching the correct plugin, so if for example you tried to authenticate user admin with password admin, which would succeed against Postgres backend, if it is checked against JWT backend first, it will throw an error as admin is not a valid JWT token. But that only means it wonât get authenticated by JWT backend, nothing else, and thatâs why that kind of message is at debug level only.
So, in these messages this is whatâs happening:
DEBU[0021] checking acl cache for loragw
DEBU[0021] Superuser check with backend Files
DEBU[0021] Superuser check with backend Postgres
DEBU[0021] Superuser check with backend JWT
DEBU[0021] jwt parse error: token contains an invalid number of segments
DEBU[0021] jwt get superuser error: token contains an invalid number of segments
DEBU[0021] Acl check with backend Files
INFO[0021] Files acl check with user loragw, topic: gateway/7276ff00080801db/rx, clientid: a45007a8-ea3a-4117-bc7f-c18728fba235 and acc: 2
INFO[0021] Files acl check passed.
DEBU[0021] user loragw acl authenticated with backend Files
DEBU[0021] setting acl cache (granted = true) for loragw
DEBU[0021] Acl is %!s(bool=true) for user loragw
The user loragw wants to write to topic gateway/7276ff00080801db/rx, so the plugin must check if itâs authorized to do so.
First, it checks for an existing cache record for that user and acl, which isnât found.
Then, before checking for the specific topic, it checks if any backend says that loragw is a superuser, as superusers have all privileges over any topic. It is in this step, checking for superuser privileges against JWT, that the âerrorâ appears, as loragw isnât a valid JWT token.
As no backend recognized the user as a superuser, specific acl check for the topic must be ran.
As you see, The Files backend correctly recognized the user is allowed to write to the topic, and thus authorized him.
In order to prevent repeating this steps if the user were to write to the same topic soon, the plugin stores a record holding the user and topic (and access too) at its ACL cache (thereâs also an Auth cache, both are just different prefixes in the same Redis DB but may hace different expiration times configured).
That is the regular process the plugin follows to check if a user is allowed to publish or subscribe to a given topic.
Finally, if you hit CTL + C at the terminal, or if you exit the terminal, this manual instance of mosquitto should finish. Then you can just start it as a service again to have it running as always. Just make sure that the service is indeed getting its configuration from the same location and it will work the same as if it was manually started. And, as mentioned, the log at /var/log/mosquitto/mosquitto.log keeps messages that have more to do with connection statuses, not mosquittoâs auth. On the other hand, systemd logs, which can be checked with journalctl, will show the messages you saw in the manual execution. For example, in my system if I restart my mosquitto service and try to subscribe with user admin (and then exit mosquitto_sub and try again to see cache is working), I get this when I check the logs with:
sudo journalctl -u mosquitto -f -n 50
systemd[1]: Stopping Mosquitto MQTT v3.1/v3.1.1 server...
Mosquitto[889]: time="2018-02-07T15:53:20-03:00" level=info msg="Cleaning up plugin"
systemd[1]: Stopped Mosquitto MQTT v3.1/v3.1.1 server.
systemd[1]: Started Mosquitto MQTT v3.1/v3.1.1 server.
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="Got 3 users from passwords file.\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {gateway/+/stats 2} for user loraserver_gw\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {gateway/+/rx 2} for user loraserver_gw\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {gateway/+/tx 1} for user loraserver_gw\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {gateway/+/stats 1} for user loraserver_ns\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {gateway/+/tx 2} for user loraserver_ns\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {gateway/+/rx 1} for user loraserver_ns\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {application/+/node/+/rx 2} for user loraserver_as\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {application/+/node/+/join 2} for user loraserver_as\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {application/+/node/+/ack 2} for user loraserver_as\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {application/+/node/+/error 2} for user loraserver_as\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {application/+/node/+/tx 1} for user loraserver_as\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {application/+/device/+/data 2} for user loraserver_as\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="created aclrecord {application/+/device/+/alarm 2} for user loraserver_as\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="Got 13 lines from acl file.\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="Backend registered: Files\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="Backend registered: Postgres\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="Backend registered: JWT\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="Backend registered: Redis\n"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="Cache activated"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="started cache redis client"
Mosquitto[26028]: time="2018-02-07T15:53:20-03:00" level=info msg="flushed cache"
Mosquitto[26028]: time="2018-02-07T15:53:21-03:00" level=debug msg="checking auth cache for loraserver_gw\n"
Mosquitto[26028]: time="2018-02-07T15:53:21-03:00" level=debug msg="checking user loraserver_gw with backend Files\n"
Mosquitto[26028]: time="2018-02-07T15:53:21-03:00" level=debug msg="user loraserver_gw authenticated with backend Files\n"
Mosquitto[26028]: time="2018-02-07T15:53:21-03:00" level=debug msg="setting auth cache for loraserver_gw\n"
Mosquitto[26028]: time="2018-02-07T15:53:36-03:00" level=debug msg="checking auth cache for admin\n"
Mosquitto[26028]: time="2018-02-07T15:53:36-03:00" level=debug msg="checking user admin with backend Files\n"
Mosquitto[26028]: time="2018-02-07T15:53:36-03:00" level=debug msg="checking user admin with backend Postgres\n"
Mosquitto[26028]: time="2018-02-07T15:53:36-03:00" level=debug msg="user admin authenticated with backend Postgres\n"
Mosquitto[26028]: time="2018-02-07T15:53:36-03:00" level=debug msg="setting auth cache for admin\n"
Mosquitto[26028]: time="2018-02-07T15:53:45-03:00" level=debug msg="checking auth cache for admin\n"
Mosquitto[26028]: time="2018-02-07T15:53:45-03:00" level=debug msg="found in cache: admin\n"
@RogerioCassares no problem, and thanks for giving the plugin a test!
JWT will be used when you subscribe or publish to a topic and the username holds a valid JWT token (the password doesnât matter, it will be omitted by the backend). For example, taking a random jwt token, you could do this from mosquitto_sub:
If that token was correctly generated by lora-app-server for a user âusernameâ with password âpassâ when logging in, then JWT backend would authenticate/authorize the user âusernameâ correctly when subscribing through mosquitto_sub or other tool.
For example, I rely on the JWT backend to subscribe to mqtt data topics from the lora-app-serverâs frontend (with this js mqqt client), using the token that I get when I log in with my user.
