-
Type: Bug
-
Resolution: Fixed
-
Priority: Major - P3
-
Affects Version/s: None
-
Component/s: None
-
None
This is a regression introduced by GODRIVER-803. The commit before that one does not have this problem.
How to reproduce:
- Start a 1-node replica set with auth and a keyfile containing "testkeyfilecontents"
- Run the attached go-driver-auth.go program. The following happens
[tim@jazzstep-2 tst]$ go run go-driver-auth.go panic: (Unauthorized) not authorized on admin to execute command { serverStatus: 1, locks: false, recordStats: false, $db: "admin", $readPreference: { mode: "primaryPreferred" } } goroutine 1 [running]: main.main() /Users/tim/tst/go-driver-auth.go:38 +0x520 exit status 2
Note that I did not even use the new AuthenticateArbiter option.
MongoDB logs show that authentication is not even happening.
2019-02-21T15:23:26.860-0500 I CONTROL [main] Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none' 2019-02-21T15:23:26.877-0500 I CONTROL [initandlisten] MongoDB starting : pid=74533 port=27017 dbpath=db1 64-bit host=jazzstep-2.local 2019-02-21T15:23:26.877-0500 I CONTROL [initandlisten] db version v4.0.4 2019-02-21T15:23:26.877-0500 I CONTROL [initandlisten] git version: f288a3bdf201007f3693c58e140056adf8b04839 2019-02-21T15:23:26.878-0500 I CONTROL [initandlisten] allocator: system 2019-02-21T15:23:26.878-0500 I CONTROL [initandlisten] modules: none 2019-02-21T15:23:26.878-0500 I CONTROL [initandlisten] build environment: 2019-02-21T15:23:26.878-0500 I CONTROL [initandlisten] distarch: x86_64 2019-02-21T15:23:26.878-0500 I CONTROL [initandlisten] target_arch: x86_64 2019-02-21T15:23:26.878-0500 I CONTROL [initandlisten] options: { replication: { replSet: "rs0" }, security: { keyFile: "keyfile" }, storage: { dbPath: "db1" } } 2019-02-21T15:23:26.879-0500 I STORAGE [initandlisten] Detected data files in db1 created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'. 2019-02-21T15:23:26.879-0500 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=7680M,session_max=20000,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),statistics_log=(wait=0),verbose=(recovery_progress), 2019-02-21T15:23:27.580-0500 I STORAGE [initandlisten] WiredTiger message [1550780607:580270][74533:0x119acd5c0], txn-recover: Main recovery loop: starting at 1/22016 to 2/256 2019-02-21T15:23:27.661-0500 I STORAGE [initandlisten] WiredTiger message [1550780607:661341][74533:0x119acd5c0], txn-recover: Recovering log 1 through 2 2019-02-21T15:23:27.723-0500 I STORAGE [initandlisten] WiredTiger message [1550780607:723243][74533:0x119acd5c0], txn-recover: Recovering log 2 through 2 2019-02-21T15:23:27.765-0500 I STORAGE [initandlisten] WiredTiger message [1550780607:765375][74533:0x119acd5c0], txn-recover: Set global recovery timestamp: 0 2019-02-21T15:23:27.836-0500 I RECOVERY [initandlisten] WiredTiger recoveryTimestamp. Ts: Timestamp(0, 0) 2019-02-21T15:23:27.876-0500 I CONTROL [initandlisten] 2019-02-21T15:23:27.876-0500 I CONTROL [initandlisten] ** WARNING: This server is bound to localhost. 2019-02-21T15:23:27.876-0500 I CONTROL [initandlisten] ** Remote systems will be unable to connect to this server. 2019-02-21T15:23:27.876-0500 I CONTROL [initandlisten] ** Start the server with --bind_ip <address> to specify which IP 2019-02-21T15:23:27.876-0500 I CONTROL [initandlisten] ** addresses it should serve responses from, or with --bind_ip_all to 2019-02-21T15:23:27.876-0500 I CONTROL [initandlisten] ** bind to all interfaces. If this behavior is desired, start the 2019-02-21T15:23:27.876-0500 I CONTROL [initandlisten] ** server with --bind_ip 127.0.0.1 to disable this warning. 2019-02-21T15:23:27.876-0500 I CONTROL [initandlisten] 2019-02-21T15:23:27.921-0500 I FTDC [initandlisten] Initializing full-time diagnostic data capture with directory 'db1/diagnostic.data' 2019-02-21T15:23:27.926-0500 I REPL [initandlisten] Did not find local voted for document at startup. 2019-02-21T15:23:27.930-0500 I REPL [initandlisten] Rollback ID is 1 2019-02-21T15:23:27.930-0500 I REPL [initandlisten] Did not find local replica set configuration document at startup; NoMatchingDocument: Did not find replica set configuration document in local.system.replset 2019-02-21T15:23:27.930-0500 I CONTROL [LogicalSessionCacheRefresh] Sessions collection is not set up; waiting until next sessions refresh interval: Replication has not yet been configured 2019-02-21T15:23:27.930-0500 I NETWORK [initandlisten] waiting for connections on port 27017 2019-02-21T15:23:27.930-0500 I CONTROL [LogicalSessionCacheReap] Sessions collection is not set up; waiting until next sessions reap interval: config.system.sessions does not exist 2019-02-21T15:23:39.084-0500 I NETWORK [listener] connection accepted from 127.0.0.1:62305 #1 (1 connection now open) 2019-02-21T15:23:39.084-0500 I ACCESS [conn1] note: no users configured in admin.system.users, allowing localhost access 2019-02-21T15:23:39.085-0500 I NETWORK [listener] connection accepted from 127.0.0.1:62306 #2 (2 connections now open) 2019-02-21T15:23:39.085-0500 I NETWORK [conn2] received client metadata from 127.0.0.1:62306 conn2: { driver: { name: "mongo-go-driver", version: "v1.0.0-rc1+prerelease" }, os: { type: "darwin", architecture: "amd64" }, platform: "go1.10.5" } 2019-02-21T15:23:39.085-0500 I ACCESS [conn2] Unauthorized: not authorized on admin to execute command { serverStatus: 1, locks: false, recordStats: false, $db: "admin", $readPreference: { mode: "primaryPreferred" } } 2019-02-21T15:23:39.086-0500 I NETWORK [conn2] end connection 127.0.0.1:62306 (1 connection now open) 2019-02-21T15:23:39.086-0500 I NETWORK [conn1] end connection 127.0.0.1:62305 (0 connections now open)
I am able to login using the keyfile using the mongo shell or the Go driver master commit before the GODRIVER-803 fix.
- is caused by
-
GODRIVER-803 Add option to allow authenticating with an arbiter
- Closed