Friday, July 5, 2019

authentication - MongoDB in Docker claims user was successfully created, but login still fails

I am trying to construct a Docker image with MongoDB w/auth and a configured user. However, even though creating the user works, I can't seem to use that user. The application is a Dropwizard 0.8 project.


I assume that there is some problem with the user creation, but as you can see from the log below, Mongo claims that the user was successfully created.


The command I use to build the image:


docker build -t id-srv -f Dockerfile . && docker-compose up --build

Here are the logs from the my-mongo build:


$ docker build -t my-mongo -f Dockerfile-mongo . --no-cache
Sending build context to Docker daemon 73.08 MB
Step 1 : FROM mongo:3.3
---> aa57b208cc5d
Step 2 : RUN su - mongodb -c "mongod" & sleep 5; mongo --eval "db.createUser({user: 'peter', pwd: 'password', roles: [{role:'readWrite',db:'progether-id'}]})" a
dmin
---> Running in d75db07d9922
2016-10-03T12:08:27.655+0000 I CONTROL [initandlisten] MongoDB starting : pid=10 port=27017 dbpath=/data/db 64-bit host=383850eeb47b
2016-10-03T12:08:27.655+0000 I CONTROL [initandlisten] db version v3.3.15
2016-10-03T12:08:27.655+0000 I CONTROL [initandlisten] git version: 520f5571d039b57cf9c319b49654909828971073
2016-10-03T12:08:27.655+0000 I CONTROL [initandlisten] OpenSSL version: OpenSSL 1.0.1t 3 May 2016
2016-10-03T12:08:27.656+0000 I CONTROL [initandlisten] allocator: tcmalloc
2016-10-03T12:08:27.656+0000 I CONTROL [initandlisten] modules: none
2016-10-03T12:08:27.656+0000 I CONTROL [initandlisten] build environment:
2016-10-03T12:08:27.656+0000 I CONTROL [initandlisten] distmod: debian81
2016-10-03T12:08:27.656+0000 I CONTROL [initandlisten] distarch: x86_64
2016-10-03T12:08:27.656+0000 I CONTROL [initandlisten] target_arch: x86_64
2016-10-03T12:08:27.656+0000 I CONTROL [initandlisten] options: {}
2016-10-03T12:08:27.661+0000 I STORAGE [initandlisten]
2016-10-03T12:08:27.661+0000 I STORAGE [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
2016-10-03T12:08:27.661+0000 I STORAGE [initandlisten] See http://dochub.mongodb.org/core/prodnotes-filesystem
2016-10-03T12:08:27.661+0000 I STORAGE [initandlisten] wiredtiger_open config: create,cache_size=256M,session_max=20000,eviction=(threads_max=4),config_base=fa
lse,statistics=(fast),log=(enabled=true,archive=true,path=journal,compressor=snappy),file_manager=(close_idle_time=100000),checkpoint=(wait=60,log_size=2GB),sta
tistics_log=(wait=0),
2016-10-03T12:08:27.696+0000 I CONTROL [initandlisten]
2016-10-03T12:08:27.696+0000 I CONTROL [initandlisten] ** NOTE: This is a development version (3.3.15) of MongoDB.
2016-10-03T12:08:27.696+0000 I CONTROL [initandlisten] ** Not recommended for production.
2016-10-03T12:08:27.696+0000 I CONTROL [initandlisten]
2016-10-03T12:08:27.697+0000 I CONTROL [initandlisten] ** WARNING: Access control is not enabled for the database.
2016-10-03T12:08:27.697+0000 I CONTROL [initandlisten] ** Read and write access to data and configuration is unrestricted.
2016-10-03T12:08:27.697+0000 I CONTROL [initandlisten]
2016-10-03T12:08:27.697+0000 I CONTROL [initandlisten]
2016-10-03T12:08:27.697+0000 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
2016-10-03T12:08:27.697+0000 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2016-10-03T12:08:27.698+0000 I CONTROL [initandlisten]
2016-10-03T12:08:27.698+0000 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
2016-10-03T12:08:27.698+0000 I CONTROL [initandlisten] ** We suggest setting it to 'never'
2016-10-03T12:08:27.698+0000 I CONTROL [initandlisten]
2016-10-03T12:08:27.707+0000 I FTDC [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/diagnostic.data'
2016-10-03T12:08:27.716+0000 I INDEX [initandlisten] build index on: admin.system.version properties: { v: 2, key: { version: 1 }, name: "incompatible_with_v
ersion_32", ns: "admin.system.version" }
2016-10-03T12:08:27.716+0000 I INDEX [initandlisten] building index using bulk method
2016-10-03T12:08:27.717+0000 I INDEX [initandlisten] build index done. scanned 0 total records. 0 secs
2016-10-03T12:08:27.719+0000 I NETWORK [thread1] waiting for connections on port 27017
MongoDB shell version v3.3.15
connecting to: mongodb://127.0.0.1:27017/admin
2016-10-03T12:08:32.766+0000 I NETWORK [thread1] connection accepted from 127.0.0.1:45594 #1 (1 connection now open)
2016-10-03T12:08:32.767+0000 I NETWORK [conn1] received client metadata from 127.0.0.1:45594 conn1: { application: { name: "MongoDB Shell" }, driver: { name: "
MongoDB Internal Client", version: "3.3.15" }, os: { type: "Linux", name: "PRETTY_NAME="Debian GNU/Linux 8 (jessie)"", architecture: "x86_64", version: "Kernel
4.4.16-boot2docker" } }
MongoDB server version: 3.3.15
Successfully added user: {
"user" : "peter",
"roles" : [
{
"role" : "readWrite",
"db" : "progether-id"
}
]
}
2016-10-03T12:08:32.792+0000 I - [conn1] end connection 127.0.0.1:45594 (1 connection now open)
---> 7095cab20aa3
Removing intermediate container d75db07d9922
Step 3 : RUN rm /tmp/mongodb-*.sock
---> Running in 418278f9b413
---> 3f0af9638969
Removing intermediate container 418278f9b413
Step 4 : CMD mongod --auth --smallfiles
---> Running in cf50e0920661
---> 41b81d0634b3
Removing intermediate container cf50e0920661
Successfully built 41b81d0634b3
SECURITY WARNING: You are building a Docker image from Windows against a non-Windows Docker host. All files and directories added to build context will have '-r
wxr-xr-x' permissions. It is recommended to double check and reset permissions for sensitive files and directories.

Here are the logs from docker-compose:


$ docker-compose up --build
Starting identityservice_mongo_1
Starting identityservice_identify-service_1
Attaching to identityservice_mongo_1, identityservice_identify-service_1
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.182+0000 I CONTROL [initandlisten] MongoDB starting : pid=1 port=27017 dbpath=/data/db 64-bit host=e74532b51
0ca
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.183+0000 I CONTROL [initandlisten] db version v3.3.15
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.183+0000 I CONTROL [initandlisten] git version: 520f5571d039b57cf9c319b49654909828971073
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.183+0000 I CONTROL [initandlisten] OpenSSL version: OpenSSL 1.0.1t 3 May 2016
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.183+0000 I CONTROL [initandlisten] allocator: tcmalloc
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.183+0000 I CONTROL [initandlisten] modules: none
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.184+0000 I CONTROL [initandlisten] build environment:
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.184+0000 I CONTROL [initandlisten] distmod: debian81
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.184+0000 I CONTROL [initandlisten] distarch: x86_64
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.184+0000 I CONTROL [initandlisten] target_arch: x86_64
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.184+0000 I CONTROL [initandlisten] options: { security: { authorization: "enabled" }, storage: { mmapv1: { s
mallFiles: true } } }
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.188+0000 I - [initandlisten] Detected data files in /data/db created by the 'mmapv1' storage engine, s
o setting the active storage engine to 'mmapv1'.
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.192+0000 I JOURNAL [initandlisten] journal dir=/data/db/journal
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.193+0000 I JOURNAL [initandlisten] recover : no journal files present, no recovery needed
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.231+0000 I JOURNAL [durability] Durability thread started
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.231+0000 I JOURNAL [journal writer] Journal writer thread started
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.232+0000 I CONTROL [initandlisten]
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.232+0000 I CONTROL [initandlisten] ** NOTE: This is a development version (3.3.15) of MongoDB.
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.232+0000 I CONTROL [initandlisten] ** Not recommended for production.
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.232+0000 I CONTROL [initandlisten]
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.233+0000 I CONTROL [initandlisten]
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.233+0000 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/enabled is 'always'.
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.233+0000 I CONTROL [initandlisten] ** We suggest setting it to 'never'
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.233+0000 I CONTROL [initandlisten]
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.233+0000 I CONTROL [initandlisten] ** WARNING: /sys/kernel/mm/transparent_hugepage/defrag is 'always'.
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.233+0000 I CONTROL [initandlisten] ** We suggest setting it to 'never'
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.233+0000 I CONTROL [initandlisten]
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.237+0000 I FTDC [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/d
iagnostic.data'
←[36mmongo_1 |←[0m 2016-10-03T12:03:21.238+0000 I NETWORK [thread1] waiting for connections on port 27017
←[33midentify-service_1 |←[0m INFO [2016-10-03 12:03:23,472] org.eclipse.jetty.util.log: Logging initialized @2104ms
←[33midentify-service_1 |←[0m DEBUG [2016-10-03 12:03:23,564] com.progether.services.id.IdService: initializing application
←[33midentify-service_1 |←[0m DEBUG [2016-10-03 12:03:23,566] com.progether.services.id.IdService: initializing application/morphia
←[33midentify-service_1 |←[0m INFO [2016-10-03 12:03:23,577] org.mongodb.morphia.logging.MorphiaLoggerFactory: LoggerImplFactory set to org.mongodb.morphia.lo
gging.jdk.JDKLoggerFactory
←[33midentify-service_1 |←[0m WARN [2016-10-03 12:03:24,346] org.mongodb.morphia.mapping.validation.MappingValidator: MisplacedProperty complained about com.p
rogether.services.id.representation.UserSession.expired : com.progether.services.id.representation.UserSession.expired is annotated as @Property but is a type t
hat cannot be mapped simply (type is java.time.OffsetDateTime).
←[33midentify-service_1 |←[0m WARN [2016-10-03 12:03:24,347] org.mongodb.morphia.mapping.validation.MappingValidator: MisplacedProperty complained about com.p
rogether.services.id.representation.UserSession.lastAccess : com.progether.services.id.representation.UserSession.lastAccess is annotated as @Property but is a
type that cannot be mapped simply (type is java.time.OffsetDateTime).
←[33midentify-service_1 |←[0m WARN [2016-10-03 12:03:24,348] org.mongodb.morphia.mapping.validation.MappingValidator: MisplacedProperty complained about com.p
rogether.services.id.representation.UserSession.started : com.progether.services.id.representation.UserSession.started is annotated as @Property but is a type t
hat cannot be mapped simply (type is java.time.OffsetDateTime).
←[33midentify-service_1 |←[0m WARN [2016-10-03 12:03:24,365] org.mongodb.morphia.mapping.MappedField: Parameterized types are treated as untyped Objects. See
field 'properties' on class com.progether.services.id.representation.UserIdentity
←[33midentify-service_1 |←[0m INFO [2016-10-03 12:03:24,476] org.mongodb.driver.cluster: Cluster created with settings {hosts=[mongo:27017], mode=SINGLE, requ
iredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms', maxWaitQueueSize=500}
←[36mmongo_1 |←[0m 2016-10-03T12:03:24.529+0000 I NETWORK [thread1] connection accepted from 172.19.0.3:59474 #1 (1 connection now open)
←[36mmongo_1 |←[0m 2016-10-03T12:03:24.597+0000 I ACCESS [conn1] authenticate db: progether-id { authenticate: 1, user: "peter", nonce: "xxx", ke
y: "xxx" }
←[36mmongo_1 |←[0m 2016-10-03T12:03:24.597+0000 I ACCESS [conn1] Failed to authenticate peter@progether-id with mechanism MONGODB-CR: Authenticati
onFailed: UserNotFound: Could not find user peter@progether-id
←[33midentify-service_1 |←[0m INFO [2016-10-03 12:03:24,598] org.mongodb.driver.cluster: No server chosen by PrimaryServerSelector from cluster description Cl
usterDescription{type=UNKNOWN, connectionMode=SINGLE, all=[ServerDescription{address=mongo:27017, type=UNKNOWN, state=CONNECTING}]}. Waiting for 30000 ms before
timing out
←[36mmongo_1 |←[0m 2016-10-03T12:03:24.605+0000 I - [conn1] end connection 172.19.0.3:59474 (1 connection now open)
←[33midentify-service_1 |←[0m INFO [2016-10-03 12:03:24,616] org.mongodb.driver.cluster: Exception in monitor thread while connecting to server mongo:27017
←[33midentify-service_1 |←[0m ! com.mongodb.MongoCommandException: Command failed with error 18: 'auth failed' on server mongo:27017. The full response is { "o
k" : 0.0, "errmsg" : "auth failed", "code" : 18, "codeName" : "AuthenticationFailed" }
←[36mmongo_1 |←[0m 2016-10-03T12:03:25.128+0000 I NETWORK [thread1] connection accepted from 172.19.0.3:59476 #2 (1 connection now open)
←[36mmongo_1 |←[0m 2016-10-03T12:03:25.133+0000 I ACCESS [conn2] authenticate db: progether-id { authenticate: 1, user: "peter", nonce: "xxx", ke
y: "xxx" }
←[36mmongo_1 |←[0m 2016-10-03T12:03:25.133+0000 I ACCESS [conn2] Failed to authenticate peter@progether-id with mechanism MONGODB-CR: Authenticati
onFailed: UserNotFound: Could not find user peter@progether-id

Dockerfile-mongo:


FROM mongo:3.3
RUN su - mongodb -c "mongod" & sleep 5; mongo --eval "\
db.createUser({user: 'peter', pwd: 'password', roles: [{role:'readWrite',db:'progether-id'}]})" admin
RUN rm /tmp/mongodb-*.sock
CMD ["mongod", "--auth", "--smallfiles"]

docker-compose.yml:


version: '2'
services:
identify-service:
image: id-srv
ports:
- "8483:8483"
links:
- mongo
mongo:
image: my-mongo
ports:
- "27017:27017"

No comments:

Post a Comment

hard drive - Leaving bad sectors in unformatted partition?

Laptop was acting really weird, and copy and seek times were really slow, so I decided to scan the hard drive surface. I have a couple hundr...