emqx_authz_mongodb - Mongo 6 - InvalidNamespace

[mattiabenin]

Environment

• EMQX K8S: 5.0.14
• MongoDB: 6.0.3-debian-11-r0

Description

I configure EMQX security authentication and authorization with MongoDB.

Authentication works correctly.

Authorization I see this error to logs when I try to subscribe an auth topic. I receive same error also when I try publish.

2023-01-16T16:50:38.418673+00:00 [error] clientid: mqttx_f4031173, collection: mqtt_acl_external, filter: #{username => <<"test">>}, line: 95, mfa: emqx_authz_mongodb:authorize/4, msg: query_mongo_error, peername: 10.206.0.5:14435, reason: {resource_error,#{msg => #{error => {error,{error_cannot_parse_response,{op_msg_response,#{<<"$clusterTime">> => #{<<"clusterTime">> => {mongostamp,1,1673887828},<<"signature">> => #{<<"hash">> => {bin,bin,<<179,150,62,241,200,75,160,112,75,109,68,138,84,57,24,11,192,39,234,118>>},<<"keyId">> => 7186970566845267971}},<<"code">> => 73,<<"codeName">> => <<"InvalidNamespace">>,<<"errmsg">> => <<"Failed to parse namespace element">>,<<"ok">> => 0.0,<<"operationTime">> => {mongostamp,1,1673887828}}}}},id => <<"emqx_authz_mongodb:3">>,name => call_query,request => {find,mqtt_acl_external,#{username => <<"test">>},#{}},stacktrace => [{mc_connection_man,reply,1,[{file,"mc_connection_man.erl"},{line,123}]},{mc_connection_man,read,4,[{file,"mc_connection_man.erl"},{line,34}]},{mc_worker_api,find,2,[{file,"mc_worker_api.erl"},{line,288}]},{poolboy,transaction,3,[{file,"poolboy.erl"},{line,84}]},{emqx_connector_mongo,on_query,3,[{file,"emqx_connector_mongo.erl"},{line,239}]},{emqx_resource_worker,apply_query_fun,7,[{file,"emqx_resource_worker.erl"},{line,639}]},{emqx_resource_worker,do_flush,2,[{file,"emqx_resource_worker.erl"},{line,459}]},{gen_statem,loop_state_callback,11,[{file,"gen_statem.erl"},{line,1203}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,226}]}]},reason => exception}}, resource_id: <<"emqx_authz_mongodb:3">>

The document of collection:
{
"username": "test",
"permission": "allow",
"action": "all",
"topics": ["topicp1/topicp2"]
}

I try the same configuration with MongoDB version 4.4.X and it works all.

[lucabrambilla00]

Hi,

I'm facing the same issue.... need help

Thanks

[kjellwinblad]

Thanks for the report. I have tried to reproduce the issue but failed so far. Both Authentication and Authorization works when I set it up with MongoDB 6 (I use the docker image and start it like this docker run --rm -p 127.0.0.1:27017:27017 --name mymongo -d mongo:6) similarly to the example in the doc https://www.emqx.io/docs/en/v5.0/security/authz/mongodb.html#configuration.

Can you share your configuration for authentication and authorization? This might help me reproduce the issue and solve it.

[kjellwinblad]

I think the "filter" parameters might be particularly relevant.

[mattiabenin]

In the authorization setting the filter is {"username":"${username}"}

I attach configmap that I use for k8s.
configmaps.txt

[kjellwinblad]

You are getting error code 73, codeName "InvalidNamespace" and errmsg "Failed to parse namespace element" back from the MongoDB server. I'm not 100% sure what this means but my googling indicates that this means that something is incorrectly formatted. See for example this https://stackoverflow.com/questions/60394055/invalid-namespace-specified-mongoose-save-collection . Can you check the .Values.mongo_uri string and anything else that you think could be formatted incorrectly?

One thing that differs in my config (attached) compared to yours is that I have not configured a replica set but just a single server so the issue might be related to that.
cluster-override.conf.txt

[kjellwinblad]

In your config it looks like one of the filters are broken between two lines. This looks a bit suspicious but I don't think this is the issue since the filter looks alright in the error message.

[lucabrambilla00]

Hi,

I see in your cluster-override.conf.txt you use:

• standalone instead of our replicaset
• You have set no_match = "allow" , with this conf it works without checking ACL

[kjellwinblad]

Thank you. I will try to reproduce the issue again with other values for those parameters.

[kjellwinblad]

I have still not managed to reproduce this unfortunately. I have tried with replicaset, no_match = "deny", and have set up rules for a user to be both denied and allowed to publish and subscribe for different topics. All seems to work as expected when I publish to the different topics. When I publish to the denied topic I get the following in the log/erlang.log.1:

2023-01-19T14:40:55.667808+01:00 [warning] clientid: mqttx_e6478992, line: 663, mfa: emqx_channel:process_publish/2, msg: cannot_publish_to_topic, peername: 127.0.0.1:41718, reason: not_authorized, topic: d/hoo
2023-01-19T14:41:09.309475+01:00 [warning] clientid: mqttx_e6478992, ipaddr: {127,0,0,1}, line: 357, mfa: emqx_authz:authorize_non_superuser/5, msg: authorization_permission_denied, peername: 127.0.0.1:41718, source: mongodb, topic: d/#, username: <<"kjell">>

I even verified on the MongoDB side that the right queries are sent for authentication and authorization.

@mattiabenin You wrote in the issue report that you tested with EMQX 5.0.14. I did my test with a recent checkout of the master branch which is a few commits ahead of 5.014. I don't think anything has changed that affects this issue but I could have missed something. It would be great if you could test with the recent master and see if that makes any difference? If you don't want to build by yourself, there is a recent build for different platforms here:

https://github.com/emqx/emqx/actions/runs/3958201321

Look under Artifacts in the bottom of the page.

It is very difficult to find the problem if I can't reproduce it locally. If it is not fixed in the master branch you could try to simplify your environment (preferable with docker-compose or something that is easy for me to replicate) and describe in precise steps what I should to to reproduce the issue. Thank you for the collaboration.

[github-actions]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[amin-is]

I am facing same issue.
System info
EMQX: 5.0.15
MongoDB: 6.0.4
Debian 11

[EMQX: 5.0.15 with MongoDB 4 Authentication & Authorization working very well with no issues]

[EMQX: 5.0.15 with MongoDB 5 Authentication & Authorization working well but here also need to loging with admin user for mqtt DB. Another user login failed]

EMQX: 5.0.15 with MongoDB 6 Authentication & Authorization login OK with only admin user. General user (including readwrite permission) login failed. But afer login with admin user for DB mqtt ACL filter not working.

use admin
db.createUser(
  {
    user: "admin",
    pwd: "123",
    roles: [ { role: "userAdminAnyDatabase", db: "admin" }, "readWriteAnyDatabase" ]
  }
)

use mqtt
db.createUser(
  {
    user: "abc",
    pwd: "123",
    roles: [ { role: "readWrite", db: "mqtt" } ]
  }
)

---

admin> db.system.users.find()
[
  {
    _id: 'admin.admin',
    userId: new UUID("2dffbbb4-88cd-4b86-9aa8-d90ed7a0509e"),
    user: 'admin',
    db: 'admin',
    credentials: {
      'SCRAM-SHA-1': {
        iterationCount: 10000,
        salt: 'l7y66KPyN9IWq1ERnvr9vQ==',
        storedKey: 'L6g7+dXYABV11YXLqnd9eUbDXVA=',
        serverKey: '5fXZqZqIeYl/bUKZVRY1udwC51Y='
      },
      'SCRAM-SHA-256': {
        iterationCount: 15000,
        salt: 'gjxHWI2goB4KVizt+bAdzEIWRt5mRAj4SVxmWg==',
        storedKey: 'MKxX2xxOnAIXICKJAOGL95GrByOs+RoG+EXIs4UqjYk=',
        serverKey: 'aKWYookIQMaThRt1d049hhYiA0/tOdcBNpHt8icwF34='
      }
    },
    roles: [
      { role: 'userAdminAnyDatabase', db: 'admin' },
      { role: 'readWriteAnyDatabase', db: 'admin' }
    ]
  },
  {
    _id: 'mqtt.abc',
    userId: new UUID("da036cc7-4a99-4a17-85cf-42bd51cd8176"),
    user: 'abc',
    db: 'mqtt',
    credentials: {
      'SCRAM-SHA-1': {
        iterationCount: 10000,
        salt: '03a5xixDRxfC92r4MD/WBg==',
        storedKey: 'sd5txOmZcMrh477NRufMaopxzjk=',
        serverKey: 'oKRUu4LIg+Ym8Hi5MbTf98k96lQ='
      },
      'SCRAM-SHA-256': {
        iterationCount: 15000,
        salt: '/1IHKp7wok/ot5iaoAwIpja5G0oRdRMFp6qkQg==',
        storedKey: 'nNIEdQxY49OU6IC7R7bqIUfSrkO14GnEmZJCAquzXZY=',
        serverKey: 'qJKJ3d2KaockvDUfvzxXQvcP26YZZCCR3S/VlD68yoc='
      }
    },
    roles: [ { role: 'readWrite', db: 'mqtt' } ]
  }
]

---

db.mqtt_user.insert({
  "username": "user1",
  "password_hash": "a665a45920422f9d417e4867efdc4fb8a04a1f3fff1fa07e998e86f7f7a27ae3",
  "is_superuser": false,
  "salt": ""
})

db.mqtt_acl.insert(
  {
      "username": "user1",
      "permission": "allow",
      "action": "all",
      "topics": ["user1/#"]
  }
)

EMQX: 5.0.15
MongoDB: 6.0.4

journalctl -u emqx
journalctl-emqx.txt

/var/log/emqx/emqx.log.1
log-emqx.txt

[kjellwinblad]

@amin-is thanks for the information. Just to be sure that I recreate the exact same environment as you have when trying to reproduce the issue, can you also provide information about how you start MongoDB and the EMQX config that you use for authentication and authorization (if you configure using the web UI you can find the config in data/configs/cluster-override.conf).

[kjellwinblad]

@amin-is I have tried to reproduce the problem with the exact same versions that you use EMQX: 5.0.15 and MongoDB: 6.0.4. I have also tried to set up MongoDB with an admin user and a normal read write user as you describe. EMQX can authenticate to the database with the admin user but not as the normal user (so this is similar to what you report).

However, both authentication and authorization seems to work without any problem so something must still be different between our environments. I have also checked that the MongoDB command that EMQX is sending to MongoDB looks the same in my set up to the command that I can see is failing in your log file.

Can you check your MongoDB logs? Maybe there is some problem with your MongoDB set up that causes the InvalidNamespace error?

I run MongoDB in docker like this:

mkdir mongodb_data
docker run --name emqx_mongodb_authz -v `pwd`/mongodb_data:/data/db -p 127.0.0.1:27017:27017 -d mongo:6.0.4

And then connect to it with mongosh like this to add the documents and collections:

docker exec -it emqx_mongodb_authz mongosh --host 127.0.0.1:27017

Can you try to do the same and check if it is working? If it is working with this MongoDB set up then we can conclude that there is something that differs with your original MongoDB setup that causes the Authorization problem (in which case you can send me details about how you set up MongoDB so that I can reproduce the same set up).

I believe that not being able to log in to MongoDB as a normal (non-admin user) is a separate issue that probably have to do with MongoDB changing how authentication works in version 5. I can investigate if that is the case but the Authorization problem seems more serious to me so I would really like to understand how to reproduce that so that it could be fixed.

As I have written previously in this issue, the best would be if someone could provide a bullet proof way for reproducing this (e.g., a docker-compose file that can be used to recreate the issue).

@mattiabenin @lucabrambilla00 have you made any progress with this issue or is this still a problem for you?

[amin-is]

@kjellwinblad I have try on my Debian 11 OS [EMQX: 5.0.15 + MongoDB: 6.0.4] without enabling MongoDB authorization in /etc/mongod.conf and connect from EMQX Dashboard there is no issue to working Authentication & Authorization. But when i enabled authorization from /etc/mongod.conf then inside EMQX Dashboard connected with MongoDB admin user it is seen to Authentication & Authorization connected OK (also can connect from Client App) but just not working Authorization(ACL) it deny to access.

I short-out some error

/var/log/mongodb/mongod.log

{"t":{"$date":"2023-02-04T17:46:56.593+06:00"},"s":"I",  "c":"ACCESS",   "id":20250,   "ctx":"conn186","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-1","speculative":false,"principalName":"admin","authenticationDatabase":"admin","remote":"127.0.0.1:37268","extraInfo":{}}}
{"t":{"$date":"2023-02-04T17:46:56.595+06:00"},"s":"I",  "c":"NETWORK",  "id":22944,   "ctx":"conn186","msg":"Connection ended","attr":{"remote":"127.0.0.1:37268","uuid":"f0d94b6c-0d20-40b3-bd96-d057973e7fd2","connectionId":186,"connectionCount":130}}

/var/log/emqx/emqx.log.1

2023-02-04T17:35:17.121134+06:00 [error] clientid: Win-PC1675510512370, collection: mqtt_acl, filter: #{username => <<"abc">>}, line: 95, mfa: emqx_authz_mongodb:authorize/4, msg: query_mongo_error, peername: 192.168.206.1:59965, reason: {resource_error,#{msg => #{error => {error,{error_cannot_parse_response,{op_msg_response,#{<<"code">> => 73,<<"codeName">> => <<"InvalidNamespace">>,<<"errmsg">> => <<"Failed to parse namespace element">>,<<"ok">> => 0.0}}}},id => <<"emqx_authz_mongodb:5">>,name => call_query,request => {find,mqtt_acl,#{username => <<"abc">>},#{}},stacktrace => [{mc_connection_man,reply,1,[{file,"mc_connection_man.erl"},{line,123}]},{mc_connection_man,read,4,[{file,"mc_connection_man.erl"},{line,34}]},{mc_worker_api,find,2,[{file,"mc_worker_api.erl"},{line,288}]},{poolboy,transaction,3,[{file,"poolboy.erl"},{line,84}]},{emqx_connector_mongo,on_query,3,[{file,"emqx_connector_mongo.erl"},{line,239}]},{emqx_resource_worker,apply_query_fun,8,[{file,"emqx_resource_worker.erl"},{line,817}]},{emqx_resource_worker,simple_sync_query,2,[{file,"emqx_resource_worker.erl"},{line,126}]},{emqx_authz_mongodb,authorize,4,[{file,"emqx_authz_mongodb.erl"},{line,82}]},{emqx_authz,do_authorize,4,[{file,"emqx_authz.erl"},{line,389}]},{emqx_authz,authorize_non_superuser,5,[{file,"emqx_authz.erl"},{line,339}]},{emqx_hooks,safe_execute,2,[{file,"emqx_hooks.erl"},{line,200}]},{emqx_hooks,do_run_fold,3,[{file,"emqx_hooks.erl"},{line,180}]},{emqx_access_control,do_authorize,3,[{file,"emqx_access_control.erl"},{line,144}]},{emqx_access_control,authorize,3,[{file,"emqx_access_control.erl"},{line,97}]},{emqx_channel,check_pub_authz,2,[{file,"emqx_channel.erl"},{line,1839}]},{emqx_misc,pipeline,3,[{file,"emqx_misc.erl"},{line,160}]},{emqx_channel,process_publish,2,[{file,"emqx_channel.erl"},{line,641}]},{emqx_ws_connection,with_channel,3,[{file,"emqx_ws_connection.erl"},{line,741}]},{cowboy_websocket,handler_call,6,[{file,"cowboy_websocket.erl"},{line,487}]},{proc_lib,wake_up,3,[{file,"proc_lib.erl"},{line,236}]}]},reason => exception}}, resource_id: <<"emqx_authz_mongodb:5">>
2023-02-04T17:35:17.121981+06:00 [warning] clientid: Win-PC1675510512370, line: 663, mfa: emqx_channel:process_publish/2, msg: cannot_publish_to_topic, peername: 192.168.206.1:59965, reason: not_authorized, topic: abc/in

My Finding is..
When MongoDB 6 with enabled authorization then EMQX 5 (Only Authorization) not working also inside EMQX 5 Dashboard it's show both connected when login with only MongoDB admin user.

Waiting for Solutions...

[mattiabenin]

Hello, I have no good news, I tried with your build artifact and then I tried also with EMQX 5.0.15 with MongoDB 6.0.3-debian-11-r0 but I received same error. I see in the EMQX dashboard Authentication and Authorization connected. I try to connect to MongoDB with root users and with a DB users with read and write permission but I receive the same error code 73 (with default acl configuration "deny"). @kjellwinblad in your mongodb 6 do you configure backwards compatibility (setFeatureCompatibilityVersion)?

[kjellwinblad]

@mattiabenin:

@kjellwinblad in your mongodb 6 do you configure backwards compatibility (setFeatureCompatibilityVersion)?

Not explicitly at least. I use the official MongoDB Docker image started like this (so I only use default settings):

mkdir mongodb_data
docker run --name emqx_mongodb_authz -v `pwd`/mongodb_data:/data/db -p 127.0.0.1:27017:27017 -d mongo:6.0.4

@amin-is :

@kjellwinblad I have try on my Debian 11 OS [EMQX: 5.0.15 + MongoDB: 6.0.4] without enabling MongoDB authorization in /etc/mongod.conf and connect from EMQX Dashboard there is no issue to working Authentication & Authorization. But when i enabled authorization from /etc/mongod.conf then inside EMQX Dashboard connected with MongoDB admin user it is seen to Authentication & Authorization connected OK (also can connect from Client App) but just not working Authorization(ACL) it deny to access.

This, is very interesting. So what you are saying is that with "Debian 11 OS [EMQX: 5.0.15 + MongoDB: 6.0.4] without enabling MongoDB authorization in /etc/mongod.conf " both Authentication and Authorization works without problem but when authorization is enabled in /etc/mongod.conf then EMQX's Authorization stops working? Can you send me the name of the setting in /etc/mongod.conf that you changed to get the different behavior and also a copy of your /etc/mongod.conf (remember to filter out any sensitive info that might be in that file)?

[github-actions]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[lina50]

Recurrence steps：
System info
EMQX: e5.0.1
MongoDB: 6.0.4

1. start mongodb

   docker run --name emqx_mongodb_authz -p 27177:27017 -d mongo:6.0.4 --auth

2. Create admin user

   db.createUser({ user: "admin", pwd: "public", roles: [ { role: "root", db: "admin" } ] }

3. Prepare Authentication & Authorization info
   db.mqtt_user.insertOne( { "username": "emqx_u", "salt": "slat_foo123", "is_superuser": false, "password_hash": "44edc2d57cde8d79c98145003e105b90a14f1460b79186ea9cfe83942fc5abb5" } );

   db.mqtt_acl.insertOne( { "username": "emqx_u", "clientid": "client123", "ipaddress": "119.3.39.124", "permission": "deny", "action": "all", "topics": ["t/1", "a/1"] } );

4. Configure Authentication and Authorization on the dashboard

5. Subscribe t/1 topics and send messages through websocket

   Some errors found

   

[kjellwinblad]

@lina50 Thank you for the clear instructions.

[kjellwinblad]

I have managed to reproduce the issue now and am now working on finding a fix. The reason that I did not manage to reproduce it before is probably that I did not enable authentication in mongodb with the --auth parameter.

[kjellwinblad]

I have a PR with a fix here: #10098

[kjellwinblad]

PR merged into master so this will be fixed in the next release