Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Initialization of replSet fails in docker-entrypoint.sh #354

Closed
halmartin opened this issue Jun 25, 2019 · 2 comments
Closed

Initialization of replSet fails in docker-entrypoint.sh #354

halmartin opened this issue Jun 25, 2019 · 2 comments

Comments

@halmartin
Copy link

halmartin commented Jun 25, 2019 •
edited
Loading

Hello,

I am trying to create a MongoDB instance with --replSet using Docker compose.

Expected outcome: mongod is started with --replSet and rs.initiate() executes successfully.

Observed outcome: rs.initiate() fails with the error This node was not started with the replSet option.

Reading docker-entrypoint.sh it appears that mongod is not started with the supplied command arguments for initialization, causing rs.initiate() to fail.

Attaching to the Docker container shows that mongod is eventually started with --replSet as specified in the docker-compose.yml file (as expected from the contents of docker-entrypoint.sh), and rs.initiate() succeeds. However this requires manual intervention to successfully initiate the replica set.

I believe this issue is distinct from #223 and #249. Though it may be due to me misusing the /docker-entrypoint-initdb.d facility for unintended purposes.

If I am correctly interpreting the order of execution in docker-entrypoint.sh, the issue appears to be due to the fact that mongod is not started with command arguments from the docker-compose file until after scripts are executed from /docker-entrypoint-initdb.d

mongod is started:

mongo/4.0/docker-entrypoint.sh

Line 276 in c93d83e

mongo=( mongo --host 127.0.0.1 --port 27017 --quiet )

Script execution from /docker-entrypoint-initdb.d:

mongo/4.0/docker-entrypoint.sh

Line 318 in c93d83e

for f in /docker-entrypoint-initdb.d/*; do

mongod is started with arguments from command:

mongo/4.0/docker-entrypoint.sh

Line 354 in c93d83e

exec "$@"

Can you advise me on the correct order to set up MongoDB with replica sets enabled? I cannot figure out how to accomplish this with the current docker-entrypoint.sh. It does not seem to be enough that mongod is started with --replSet, if rs.initiate() is not executed:

$ docker exec -it compose-mongo_mongo_1 bash
root@e3b1725803eb:/# ps ax
   PID TTY      STAT   TIME COMMAND
     1 ?        Ssl    0:00 mongod --replSet rs0 --auth --bind_ip_all
root@e3b1725803eb:/# mongo -u $MONGO_INITDB_ROOT_USERNAME -p $MONGO_INITDB_ROOT_PASSWORD admin
MongoDB shell version v4.0.10
connecting to: mongodb://127.0.0.1:27017/admin?gssapiServiceName=mongodb
Implicit session: session { "id" : UUID("5156098c-0c8f-41c0-a8d7-4d8c0b9abff3") }
MongoDB server version: 4.0.10
Welcome to the MongoDB shell.
> rs.status()
{
        "ok" : 0,
        "errmsg" : "no replset config has been received",
        "code" : 94,
        "codeName" : "NotYetInitialized"
}

More detailed information about my environment.

Here is the contents of my docker-compose.yml file:

version: '3.3'

services:
  mongo:
    image: mongo
    restart: always
    command: --replSet rs0
    ports:
      - "27017:27017"
    volumes:
      - mdata1:/data/db:cached
      - ./deploy/mongodb:/docker-entrypoint-initdb.d
    environment:
      - MONGO_INITDB_ROOT_USERNAME=root
      - MONGO_INITDB_ROOT_PASSWORD=hunter2
      - MONGO_INITDB_DATABASE=example1

volumes:
  mdata1:
    driver: local

./deploy/mongodb contains 00_init_replSet.sh which has the following:

mongo -u $MONGO_INITDB_ROOT_USERNAME -p $MONGO_INITDB_ROOT_PASSWORD admin --eval "rs.initiate();"

When I execute docker-compose up I receive the following error:

$ docker-compose up
Creating network "compose-mongo_default" with the default driver
Creating volume "compose-mongo_mdata1" with local driver
Creating compose-mongo_mongo_1 ... done
Attaching to compose-mongo_mongo_1
mongo_1  | about to fork child process, waiting until server is ready for connections.
mongo_1  | forked process: 26
mongo_1  | 2019-06-25T09:11:07.916+0000 I CONTROL  [main] ***** SERVER RESTARTED *****
mongo_1  | 2019-06-25T09:11:07.931+0000 I CONTROL  [main] Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'
mongo_1  | 2019-06-25T09:11:07.940+0000 I CONTROL  [initandlisten] MongoDB starting : pid=26 port=27017 dbpath=/data/db 64-bit host=39c7602b0f4e
mongo_1  | 2019-06-25T09:11:07.940+0000 I CONTROL  [initandlisten] db version v4.0.10
mongo_1  | 2019-06-25T09:11:07.940+0000 I CONTROL  [initandlisten] git version: c389e7f69f637f7a1ac3cc9fae843b635f20b766
mongo_1  | 2019-06-25T09:11:07.940+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.2g  1 Mar 2016
mongo_1  | 2019-06-25T09:11:07.940+0000 I CONTROL  [initandlisten] allocator: tcmalloc
mongo_1  | 2019-06-25T09:11:07.940+0000 I CONTROL  [initandlisten] modules: none
mongo_1  | 2019-06-25T09:11:07.940+0000 I CONTROL  [initandlisten] build environment:
mongo_1  | 2019-06-25T09:11:07.940+0000 I CONTROL  [initandlisten]     distmod: ubuntu1604
mongo_1  | 2019-06-25T09:11:07.940+0000 I CONTROL  [initandlisten]     distarch: x86_64
mongo_1  | 2019-06-25T09:11:07.940+0000 I CONTROL  [initandlisten]     target_arch: x86_64
mongo_1  | 2019-06-25T09:11:07.940+0000 I CONTROL  [initandlisten] options: { net: { bindIp: "127.0.0.1", port: 27017, ssl: { mode: "disabled" } }, processManagement: { fork: true, pidFilePath: "/tmp/docker-entrypoint-temp-mongod.pid" }, systemLog: { destination: "file", logAppend: true, path: "/proc/1/fd/1" } }
mongo_1  | 2019-06-25T09:11:07.942+0000 I STORAGE  [initandlisten]
mongo_1  | 2019-06-25T09:11:07.942+0000 I STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
mongo_1  | 2019-06-25T09:11:07.942+0000 I STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
mongo_1  | 2019-06-25T09:11:07.942+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=3679M,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),
mongo_1  | 2019-06-25T09:11:08.387+0000 I STORAGE  [initandlisten] WiredTiger message [1561453868:387573][26:0x7fd226b1aa80], txn-recover: Set global recovery timestamp: 0
mongo_1  | 2019-06-25T09:11:08.436+0000 I RECOVERY [initandlisten] WiredTiger recoveryTimestamp. Ts: Timestamp(0, 0)
mongo_1  | 2019-06-25T09:11:08.495+0000 I CONTROL  [initandlisten]
mongo_1  | 2019-06-25T09:11:08.495+0000 I CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
mongo_1  | 2019-06-25T09:11:08.495+0000 I CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
mongo_1  | 2019-06-25T09:11:08.495+0000 I CONTROL  [initandlisten]
mongo_1  | 2019-06-25T09:11:08.506+0000 I STORAGE  [initandlisten] createCollection: admin.system.version with provided UUID: 165dbec9-199a-4ea8-b355-f0cfb56c247d
mongo_1  | 2019-06-25T09:11:08.545+0000 I COMMAND  [initandlisten] setting featureCompatibilityVersion to 4.0
mongo_1  | 2019-06-25T09:11:08.552+0000 I STORAGE  [initandlisten] createCollection: local.startup_log with generated UUID: e82e1e3b-7cae-43ae-8cd1-31be38469987
mongo_1  | 2019-06-25T09:11:08.595+0000 I FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db/diagnostic.data'
mongo_1  | 2019-06-25T09:11:08.599+0000 I NETWORK  [initandlisten] waiting for connections on port 27017
mongo_1  | child process started successfully, parent exiting
mongo_1  | 2019-06-25T09:11:08.634+0000 I STORAGE  [LogicalSessionCacheRefresh] createCollection: config.system.sessions with generated UUID: c3e30198-12c1-4aee-ad50-545c72ec1f12
mongo_1  | 2019-06-25T09:11:08.727+0000 I INDEX    [LogicalSessionCacheRefresh] build index on: config.system.sessions properties: { v: 2, key: { lastUse: 1 }, name: "lsidTTLIndex", ns: "config.system.sessions", expireAfterSeconds: 1800 }
mongo_1  | 2019-06-25T09:11:08.727+0000 I INDEX    [LogicalSessionCacheRefresh]          building index using bulk method; build may temporarily use up to 500 megabytes of RAM
mongo_1  | 2019-06-25T09:11:08.728+0000 I INDEX    [LogicalSessionCacheRefresh] build index done.  scanned 0 total records. 0 secs
mongo_1  | 2019-06-25T09:11:08.789+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:36362 #1 (1 connection now open)
mongo_1  | 2019-06-25T09:11:08.790+0000 I NETWORK  [conn1] received client metadata from 127.0.0.1:36362 conn1: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.10" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "16.04" } }
mongo_1  | 2019-06-25T09:11:08.792+0000 I NETWORK  [conn1] end connection 127.0.0.1:36362 (0 connections now open)
mongo_1  | 2019-06-25T09:11:08.840+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:36364 #2 (1 connection now open)
mongo_1  | 2019-06-25T09:11:08.841+0000 I NETWORK  [conn2] received client metadata from 127.0.0.1:36364 conn2: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.10" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "16.04" } }
mongo_1  | 2019-06-25T09:11:08.875+0000 I STORAGE  [conn2] createCollection: admin.system.users with generated UUID: b7314d36-7a38-4ca0-9822-6e81317ff4eb
mongo_1  | Successfully added user: {
mongo_1  |      "user" : "root",
mongo_1  |      "roles" : [
mongo_1  |              {
mongo_1  |                      "role" : "root",
mongo_1  |                      "db" : "admin"
mongo_1  |              }
mongo_1  |      ]
mongo_1  | }
mongo_1  | 2019-06-25T09:11:08.947+0000 E -        [main] Error saving history file: FileOpenFailed: Unable to open() file /home/mongodb/.dbshell: Unknown error
mongo_1  | 2019-06-25T09:11:08.955+0000 I NETWORK  [conn2] end connection 127.0.0.1:36364 (0 connections now open)
mongo_1  |
mongo_1  | /usr/local/bin/docker-entrypoint.sh: running /docker-entrypoint-initdb.d/00_init_replSet.sh
mongo_1  | MongoDB shell version v4.0.10
mongo_1  | connecting to: mongodb://127.0.0.1:27017/admin?gssapiServiceName=mongodb
mongo_1  | 2019-06-25T09:11:08.997+0000 I NETWORK  [listener] connection accepted from 127.0.0.1:36366 #3 (1 connection now open)
mongo_1  | 2019-06-25T09:11:08.998+0000 I NETWORK  [conn3] received client metadata from 127.0.0.1:36366 conn3: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "4.0.10" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "16.04" } }
mongo_1  | 2019-06-25T09:11:09.037+0000 I ACCESS   [conn3] Successfully authenticated as principal root on admin from client 127.0.0.1:36366
mongo_1  | Implicit session: session { "id" : UUID("f534ccc0-b5c8-430c-a251-c8d6bbfa710f") }
mongo_1  | MongoDB server version: 4.0.10
mongo_1  | {
mongo_1  |      "ok" : 0,
mongo_1  |      "errmsg" : "This node was not started with the replSet option",
mongo_1  |      "code" : 76,
mongo_1  |      "codeName" : "NoReplicationEnabled"
mongo_1  | }
mongo_1  | 2019-06-25T09:11:09.041+0000 I NETWORK  [conn3] end connection 127.0.0.1:36366 (0 connections now open)

I attach to the running container to check that mongod was started with the --replSet option, as specified in docker-compose.yml, and it is:

$ docker exec -it compose-mongo_mongo_1 bash
root@010871320d81:/# ps ax
   PID TTY      STAT   TIME COMMAND
     1 ?        Ssl    0:01 mongod --replSet rs0 --auth --bind_ip_all

If I then execute the contents of the script /docker-entrypoint-initdb.d/00_init_replSet.sh the replica set is successfully initiated:

root@010871320d81:/# cat /docker-entrypoint-initdb.d/00_init_replSet.sh
mongo -u $MONGO_INITDB_ROOT_USERNAME -p $MONGO_INITDB_ROOT_PASSWORD admin --eval "rs.initiate();"
root@010871320d81:/# . /docker-entrypoint-initdb.d/00_init_replSet.sh
MongoDB shell version v4.0.10
connecting to: mongodb://127.0.0.1:27017/admin?gssapiServiceName=mongodb
Implicit session: session { "id" : UUID("23f8ba5f-2da3-4976-964c-6fcc451a1b09") }
MongoDB server version: 4.0.10
{
        "info2" : "no configuration specified. Using a default configuration for the set",
        "me" : "010871320d81:27017",
        "ok" : 1
}

The following output is seen in the shell running docker-compose up:

mongo_1  | 2019-06-25T09:19:24.748+0000 I COMMAND  [conn1] command local.system.replset appName: "MongoDB Shell" command: replSetInitiate { replSetInitiate: undefined, lsid: { id: UUID("23f8ba5f-2da3-4976-964c-6fcc451a1b09") }, $db: "admin" } numYields:0 reslen:146 locks:{ Global: { acquireCount: { r: 12, w: 4, W: 2 } }, Database: { acquireCount: { r: 2, w: 3, W: 1 } }, Collection: { acquireCount: { r: 1, w: 1 } }, oplog: { acquireCount: { r: 1, w: 2 } } } storage:{} protocol:op_msg 101ms
mongo_1  | 2019-06-25T09:19:24.749+0000 I REPL     [rsSync-0] Starting oplog application
mongo_1  | 2019-06-25T09:19:24.750+0000 I REPL     [rsSync-0] transition to SECONDARY from RECOVERING
mongo_1  | 2019-06-25T09:19:24.750+0000 I REPL     [rsSync-0] conducting a dry run election to see if we could be elected. current term: 0
mongo_1  | 2019-06-25T09:19:24.751+0000 I REPL     [replexec-0] dry election run succeeded, running for election in term 1
mongo_1  | 2019-06-25T09:19:24.751+0000 I STORAGE  [replexec-0] createCollection: local.replset.election with generated UUID: c07a8e78-67df-4e8b-9613-c9828a87846f
mongo_1  | 2019-06-25T09:19:24.752+0000 I NETWORK  [conn1] end connection 127.0.0.1:36374 (0 connections now open)
mongo_1  | 2019-06-25T09:19:24.791+0000 I REPL     [replexec-0] election succeeded, assuming primary role in term 1
mongo_1  | 2019-06-25T09:19:24.791+0000 I REPL     [replexec-0] transition to PRIMARY from SECONDARY
mongo_1  | 2019-06-25T09:19:24.791+0000 I REPL     [replexec-0] Resetting sync source to empty, which was :27017
mongo_1  | 2019-06-25T09:19:24.791+0000 I REPL     [replexec-0] Entering primary catch-up mode.
mongo_1  | 2019-06-25T09:19:24.791+0000 I REPL     [replexec-0] Exited primary catch-up mode.
mongo_1  | 2019-06-25T09:19:24.791+0000 I REPL     [replexec-0] Stopping replication producer
mongo_1  | 2019-06-25T09:19:26.753+0000 I STORAGE  [rsSync-0] createCollection: config.transactions with generated UUID: b7cf46b4-3818-460c-a1ad-369f20f161e7
mongo_1  | 2019-06-25T09:19:26.791+0000 I REPL     [rsSync-0] transition to primary complete; database writes are now permitted
mongo_1  | 2019-06-25T09:19:26.792+0000 I STORAGE  [monitoring keys for HMAC] createCollection: admin.system.keys with generated UUID: 1125512c-dc10-4172-a27d-e0d5e671477a
mongo_1  | 2019-06-25T09:19:26.844+0000 I STORAGE  [WTJournalFlusher] Triggering the first stable checkpoint. Initial Data: Timestamp(1561454364, 1) PrevStable: Timestamp(0, 0) CurrStable: Timestamp(1561454366, 2)
@wglambert
Copy link

Duplicate of #339

#339 (comment)
The docker-entrypoint-initdb.d scripts run during an initialization period (and only if the database is empty), during which the container is only listening on localhost so trying to initiate a cluster during that period isn't possible as it won't resolve it's own container hostname.

@halmartin
Copy link
Author

Thanks @wglambert. I didn't notice #339

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@halmartin @wglambert