...
I create a user with role "restore" in database "admin". This user is able to successfully restore a dumped database (mongodump => mongorestore). However, with `mongorestore --drop --preserveUUID` it fails with error Failed: : error creating collection : applyOps: (Unauthorized) not authorized on admin to execute command { applyOps:... I'm not sure if this is a missing piece in documentation (https://www.mongodb.com/docs/manual/reference/built-in-roles/#mongodb-authrole-restore, https://www.mongodb.com/docs/database-tools/mongorestore) or problem with MongoDB server (using 4.4.14).
xgen-internal-githook commented on Fri, 29 Jul 2022 03:16:08 +0000: Author: {'name': 'Sara Golemon', 'email': 'sara.golemon@mongodb.com', 'username': 'sgolemon'} Message: SERVER-66651 restore builtin role needs applyOps permissions (cherry picked from commit 0ba2a32577ed1d8b2bcf33ca195dce5516a484be) Branch: v4.4 https://github.com/mongodb/mongo/commit/f5aec2516bed2833b510065b96d6ab35b3467528 xgen-internal-githook commented on Mon, 25 Jul 2022 22:04:24 +0000: Author: {'name': 'Sara Golemon', 'email': 'sara.golemon@mongodb.com', 'username': 'sgolemon'} Message: SERVER-66651 restore builtin role needs applyOps permissions (cherry picked from commit 0ba2a32577ed1d8b2bcf33ca195dce5516a484be) Branch: v6.0 https://github.com/mongodb/mongo/commit/9fb8cf43c570e4c1696df45bfced81d81f1f9afa xgen-internal-githook commented on Thu, 7 Jul 2022 15:28:05 +0000: Author: {'name': 'Sara Golemon', 'email': 'sara.golemon@mongodb.com', 'username': 'sgolemon'} Message: SERVER-66651 restore builtin role needs applyOps permissions Branch: master https://github.com/mongodb/mongo/commit/0ba2a32577ed1d8b2bcf33ca195dce5516a484be JIRAUSER1257896 commented on Tue, 28 Jun 2022 22:36:45 +0000: Hello sara.golemon@mongodb.com This change has been done on the recommendation of security team, I think security team needs to revisit if restore role should have this privilege or not. The code works as it should from the original ticket: This feature is important to products that mimic oplog application, such as mongomirror and mongorestore. However, users should not be able to bypass validation simply because they have permission to write to a collection. Instead, applyOps should require a special privilege for bypassing validation. We will create a new privilege bypassing system-level invariants in applyOps. Today, this privilege will be required in order to run applyOps at all, since we have not implemented a version of applyOps that performs validation. The privilege will be included in dbAdminAnyDatabase, which is included in the custom role atlasAdmin and the temporary user that we create for Live Imports (mongomirror). sara.golemon commented on Tue, 28 Jun 2022 22:19:16 +0000: This is a regression introduced by SERVER-36263 which was backported to 4.4.9 sending to the original committer m.maher@mongodb.com . JIRAUSER1265262 commented on Tue, 21 Jun 2022 05:06:30 +0000: Hi Ulf, After trying again, I am actually seeing your problem now. I must have forgotten to re-enable --auth on my side when reproducing the issue before. I used the same user as in my above reproduction (except made it live in admin db instead). --preserveUUID is giving me the same error: 2022-06-21T01:02:20.854-0400 using default 'dump' directory 2022-06-21T01:02:20.854-0400 preparing collections to restore from 2022-06-21T01:02:20.900-0400 reading metadata for test.test from dump/test/test.metadata.json 2022-06-21T01:02:20.912-0400 Failed: test.test: error creating collection test.test: applyOps: not authorized on admin to execute command { applyOps: [ { op: "c", ns: "test.$cmd", o: { create: "test", idIndex: { v: 2, ns: "test.test", name: "_id_", key: { _id: 1 } } }, ui: UUID("ce9b6128-3503-470e-9d92-b69651cf667f") } ], $db: "admin" } I'll pass this off to the security team for input on those permissions. Thanks for the help! Regards, Christopher ujr@insynergie.de commented on Fri, 17 Jun 2022 09:12:36 +0000: My "restoreOperator" actually lives in DB admin - so I tried the steps you outlined (inside a completely new mongodb node) in order to verify whether that might be a problem (even if it seems unlikely). But nothing changed: 2022-06-17T11:10:02.276+0200 using default 'dump' directory 2022-06-17T11:10:02.331+0200 preparing collections to restore from 2022-06-17T11:10:02.335+0200 reading metadata for test.test from dump\test\test.metadata.json 2022-06-17T11:10:02.336+0200 dropping collection test.test before restoring 2022-06-17T11:10:02.346+0200 finished restoring test.test (0 documents, 0 failures) 2022-06-17T11:10:02.346+0200 Failed: test.test: error creating collection test.test: applyOps: (Unauthorized) not authorized on admin to execute command { applyOps: [ { op: "c", ns: "test.$cmd", o: { create: "test", idIndex: { key: { _id: 1 }, v: 2, name: "_id_", ns: "test.test" } }, ui: UUID("75c02174-29d9-4cc0-b018-cd104bc2c5df") } ], lsid: { id: UUID("547ca3c3-07e2-4d72-a8eb-91d0e7755d40") }, $db: "admin" } 2022-06-17T11:10:02.346+0200 0 document(s) restored successfully. 0 document(s) failed to restore. I'm sure that user and password are correct because mongorestore works without "–preserveUUID": 2022-06-17T11:10:54.472+0200 using default 'dump' directory 2022-06-17T11:10:54.529+0200 preparing collections to restore from 2022-06-17T11:10:54.532+0200 reading metadata for test.test from dump\test\test.metadata.json 2022-06-17T11:10:54.533+0200 dropping collection test.test before restoring 2022-06-17T11:10:54.561+0200 restoring test.test from dump\test\test.bson 2022-06-17T11:10:54.583+0200 finished restoring test.test (1 document, 0 failures) 2022-06-17T11:10:54.584+0200 restoring users from dump\admin\system.users.bson 2022-06-17T11:10:54.630+0200 no indexes to restore for collection test.test 2022-06-17T11:10:54.631+0200 1 document(s) restored successfully. 0 document(s) failed to restore. Silly question - have you enabled security.authorization? Furthermore, if that matters, I'm using mongorestore 100.5.2. So here's the log (failure only): {"t":{"$date":"2022-06-17T10:53:27.559+02:00"},"s":"I", "c":"CONTROL", "id":23285, "ctx":"main","msg":"Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'"} {"t":{"$date":"2022-06-17T10:53:28.055+02:00"},"s":"W", "c":"ASIO", "id":22601, "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"} {"t":{"$date":"2022-06-17T10:53:28.055+02:00"},"s":"I", "c":"NETWORK", "id":4648602, "ctx":"main","msg":"Implicit TCP FastOpen in use."} {"t":{"$date":"2022-06-17T10:53:28.061+02:00"},"s":"I", "c":"STORAGE", "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":21096,"port":27017,"dbPath":"db","architecture":"64-bit","host":"LE-JaenickeR-1"}} {"t":{"$date":"2022-06-17T10:53:28.061+02:00"},"s":"I", "c":"CONTROL", "id":23398, "ctx":"initandlisten","msg":"Target operating system minimum version","attr":{"targetMinOS":"Windows 7/Windows Server 2008 R2"}} {"t":{"$date":"2022-06-17T10:53:28.062+02:00"},"s":"I", "c":"CONTROL", "id":23403, "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"4.4.14","gitVersion":"0b0843af97c3ec9d2c0995152d96d2aad725aab7","modules":[],"allocator":"tcmalloc","environment":{"distmod":"windows","distarch":"x86_64","target_arch":"x86_64"}}}} {"t":{"$date":"2022-06-17T10:53:28.062+02:00"},"s":"I", "c":"CONTROL", "id":51765, "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Microsoft Windows 10","version":"10.0 (build 19044)"}}} {"t":{"$date":"2022-06-17T10:53:28.063+02:00"},"s":"I", "c":"CONTROL", "id":21951, "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"config":"mongod.cfg","net":{"bindIp":"127.0.0.1, ::1","ipv6":true},"security":{"authorization":"enabled"},"storage":{"dbPath":"db","directoryPerDB":true,"journal":{"enabled":true},"wiredTiger":{"engineConfig":{"cacheSizeGB":1.0}}}}}} {"t":{"$date":"2022-06-17T10:53:28.065+02:00"},"s":"I", "c":"STORAGE", "id":22270, "ctx":"initandlisten","msg":"Storage engine to use detected by data files","attr":{"dbpath":"db","storageEngine":"wiredTiger"}} {"t":{"$date":"2022-06-17T10:53:28.066+02:00"},"s":"I", "c":"STORAGE", "id":22315, "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=1024M,session_max=33000,eviction=(threads_min=4,threads_max=4),config_base=false,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000,close_scan_interval=10,close_handle_minimum=250),statistics_log=(wait=0),verbose=[recovery_progress,checkpoint_progress,compact_progress],"}} {"t":{"$date":"2022-06-17T10:53:28.095+02:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1655456008:95116][21096:140710929716560], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 6 through 7"}} {"t":{"$date":"2022-06-17T10:53:28.237+02:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1655456008:237137][21096:140710929716560], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 7 through 7"}} {"t":{"$date":"2022-06-17T10:53:28.321+02:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1655456008:321156][21096:140710929716560], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Main recovery loop: starting at 6/5888 to 7/256"}} {"t":{"$date":"2022-06-17T10:53:28.467+02:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1655456008:466151][21096:140710929716560], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 6 through 7"}} {"t":{"$date":"2022-06-17T10:53:28.552+02:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1655456008:552193][21096:140710929716560], txn-recover: [WT_VERB_RECOVERY_PROGRESS] Recovering log 7 through 7"}} {"t":{"$date":"2022-06-17T10:53:28.634+02:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1655456008:634117][21096:140710929716560], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global recovery timestamp: (0, 0)"}} {"t":{"$date":"2022-06-17T10:53:28.634+02:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1655456008:634117][21096:140710929716560], txn-recover: [WT_VERB_RECOVERY | WT_VERB_RECOVERY_PROGRESS] Set global oldest timestamp: (0, 0)"}} {"t":{"$date":"2022-06-17T10:53:28.637+02:00"},"s":"I", "c":"STORAGE", "id":22430, "ctx":"initandlisten","msg":"WiredTiger message","attr":{"message":"[1655456008:637114][21096:140710929716560], WT_SESSION.checkpoint: [WT_VERB_CHECKPOINT_PROGRESS] saving checkpoint snapshot min: 1, snapshot max: 1 snapshot count: 0, oldest timestamp: (0, 0) , meta checkpoint timestamp: (0, 0) base write gen: 101"}} {"t":{"$date":"2022-06-17T10:53:28.661+02:00"},"s":"I", "c":"STORAGE", "id":4795906, "ctx":"initandlisten","msg":"WiredTiger opened","attr":{"durationMillis":595}} {"t":{"$date":"2022-06-17T10:53:28.662+02:00"},"s":"I", "c":"RECOVERY", "id":23987, "ctx":"initandlisten","msg":"WiredTiger recoveryTimestamp","attr":{"recoveryTimestamp":{"$timestamp":{"t":0,"i":0}}}} {"t":{"$date":"2022-06-17T10:53:28.667+02:00"},"s":"I", "c":"STORAGE", "id":4366408, "ctx":"initandlisten","msg":"No table logging settings modifications are required for existing WiredTiger tables","attr":{"loggingEnabled":true}} {"t":{"$date":"2022-06-17T10:53:28.671+02:00"},"s":"I", "c":"STORAGE", "id":22262, "ctx":"initandlisten","msg":"Timestamp monitor starting"} {"t":{"$date":"2022-06-17T10:53:28.690+02:00"},"s":"I", "c":"STORAGE", "id":20536, "ctx":"initandlisten","msg":"Flow Control is enabled on this deployment"} {"t":{"$date":"2022-06-17T10:53:29.233+02:00"},"s":"W", "c":"FTDC", "id":23718, "ctx":"initandlisten","msg":"Failed to initialize Performance Counters for FTDC","attr":{"error":{"code":179,"codeName":"WindowsPdhError","errmsg":"PdhExpandCounterPathW failed with 'Das angegebene Objekt wurde nicht auf dem Computer gefunden.' for counter '\\Memory\\Available Bytes'"}}} {"t":{"$date":"2022-06-17T10:53:29.233+02:00"},"s":"I", "c":"FTDC", "id":20625, "ctx":"initandlisten","msg":"Initializing full-time diagnostic data capture","attr":{"dataDirectory":"db/diagnostic.data"}} {"t":{"$date":"2022-06-17T10:53:29.235+02:00"},"s":"I", "c":"REPL", "id":6015317, "ctx":"initandlisten","msg":"Setting new configuration state","attr":{"newState":"ConfigReplicationDisabled","oldState":"ConfigPreStart"}} {"t":{"$date":"2022-06-17T10:53:29.240+02:00"},"s":"I", "c":"NETWORK", "id":23015, "ctx":"listener","msg":"Listening on","attr":{"address":"127.0.0.1"}} {"t":{"$date":"2022-06-17T10:53:29.240+02:00"},"s":"I", "c":"NETWORK", "id":23015, "ctx":"listener","msg":"Listening on","attr":{"address":"::1"}} {"t":{"$date":"2022-06-17T10:53:29.240+02:00"},"s":"I", "c":"NETWORK", "id":23016, "ctx":"listener","msg":"Waiting for connections","attr":{"port":27017,"ssl":"off"}} {"t":{"$date":"2022-06-17T10:53:35.229+02:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"[::1]:62350","connectionId":1,"connectionCount":1}} {"t":{"$date":"2022-06-17T10:53:35.229+02:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"[::1]:62349","connectionId":2,"connectionCount":2}} {"t":{"$date":"2022-06-17T10:53:35.232+02:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn2","msg":"client metadata","attr":{"remote":"[::1]:62349","client":"conn2","doc":{"driver":{"name":"mongo-go-driver","version":"v1.7.1"},"os":{"type":"windows","architecture":"amd64"},"platform":"go1.16.7","application":{"name":"mongorestore"}}}} {"t":{"$date":"2022-06-17T10:53:35.232+02:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn1","msg":"client metadata","attr":{"remote":"[::1]:62350","client":"conn1","doc":{"driver":{"name":"mongo-go-driver","version":"v1.7.1"},"os":{"type":"windows","architecture":"amd64"},"platform":"go1.16.7","application":{"name":"mongorestore"}}}} {"t":{"$date":"2022-06-17T10:53:35.234+02:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"[::1]:62351","connectionId":3,"connectionCount":3}} {"t":{"$date":"2022-06-17T10:53:35.234+02:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn3","msg":"client metadata","attr":{"remote":"[::1]:62351","client":"conn3","doc":{"driver":{"name":"mongo-go-driver","version":"v1.7.1"},"os":{"type":"windows","architecture":"amd64"},"platform":"go1.16.7","application":{"name":"mongorestore"}}}} {"t":{"$date":"2022-06-17T10:53:35.250+02:00"},"s":"I", "c":"ACCESS", "id":20250, "ctx":"conn3","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":true,"principalName":"test","authenticationDatabase":"test","remote":"[::1]:62351","extraInfo":{}}} {"t":{"$date":"2022-06-17T10:53:35.315+02:00"},"s":"I", "c":"ACCESS", "id":20436, "ctx":"conn3","msg":"Checking authorization failed","attr":{"error":{"code":13,"codeName":"Unauthorized","errmsg":"not authorized on admin to execute command { applyOps: [ { op: \"c\", ns: \"test.$cmd\", o: { create: \"test\", idIndex: { key: { _id: 1 }, v: 2, name: \"_id_\", ns: \"test.test\" } }, ui: UUID(\"75c02174-29d9-4cc0-b018-cd104bc2c5df\") } ], lsid: { id: UUID(\"796694d7-bb1f-4b40-bd32-8ef73f8a8179\") }, $db: \"admin\" }"}}} {"t":{"$date":"2022-06-17T10:53:35.317+02:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn1","msg":"Connection ended","attr":{"remote":"[::1]:62350","connectionId":1,"connectionCount":2}} {"t":{"$date":"2022-06-17T10:53:35.317+02:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn3","msg":"Connection ended","attr":{"remote":"[::1]:62351","connectionId":3,"connectionCount":1}} {"t":{"$date":"2022-06-17T10:53:36.334+02:00"},"s":"W", "c":"NETWORK", "id":4615610, "ctx":"conn2","msg":"Failed to check socket connectivity","attr":{"error":"Der Vorgang wurde erfolgreich beendet."}} {"t":{"$date":"2022-06-17T10:53:36.335+02:00"},"s":"I", "c":"-", "id":20883, "ctx":"conn2","msg":"Interrupted operation as its client disconnected","attr":{"opId":96}} {"t":{"$date":"2022-06-17T10:53:36.339+02:00"},"s":"I", "c":"NETWORK", "id":22989, "ctx":"conn2","msg":"Error sending response to client. Ending connection from remote","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection reset by peer"},"remote":"[::1]:62349","connectionId":2}} {"t":{"$date":"2022-06-17T10:53:36.340+02:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn2","msg":"Connection ended","attr":{"remote":"[::1]:62349","connectionId":2,"connectionCount":0}} JIRAUSER1265262 commented on Thu, 16 Jun 2022 19:01:24 +0000: Hi Ulf, Thanks for your report. I went ahead and attempted reproducing your issue but am not sure what your problem is exactly. I did the following: 1) started a single mongod node running 4.4.14 2) created a user: use test db.createUser( { user: "test", pwd: "password", roles: [{"role": "restore", db: "admin"}] }) 3) Inserted a test document db.test.insert({"test": 1}) 4) Ran mongodump 5) Ran mongorestore: mongorestore --drop --preserveUUID --username test --password password --authenticationDatabase test 6) Observed no error 2022-06-16T15:03:45.052-0400 using default 'dump' directory 2022-06-16T15:03:45.052-0400 preparing collections to restore from 2022-06-16T15:03:45.078-0400 reading metadata for test.test from dump/test/test.metadata.json 2022-06-16T15:03:45.110-0400 restoring test.test from dump/test/test.bson 2022-06-16T15:03:45.124-0400 no indexes to restore 2022-06-16T15:03:45.124-0400 finished restoring test.test (1 document) 2022-06-16T15:03:45.124-0400 restoring users from dump/admin/system.users.bson 2022-06-16T15:03:45.203-0400 done I would double check that you are adding your user correctly, and consider specifying --username, --password, and --authenticationDatabase as appropriate in your command line. If that fails, try it again and upload your mongod logs to the ticket to investigate further. Regards, Christopher