search

5e-bits / 5e-srd-api

REST API to access D&D 5th Edition SRD database
MIT License
481 stars 156 forks source link

'Docker compose up' locks up during sharding #51

Closed jtompkins84 closed 4 years ago

jtompkins84 commented 4 years ago

Docker compose was working fine before commit da600ded45cb24ae0c9733b0ae4ca8f379dd2b19. Running docker-compose up --build now locks up during sharding of the DB after exiting with exit code: 5e-srd-api_api_1 exited with code 127.

Log:

Step 1/6 : FROM node:12.4.0-alpine
 ---> d4edda39fb81
Step 2/6 : WORKDIR /app
 ---> Using cache
 ---> b7b3b122f618
Step 3/6 : COPY package.json package-lock.json /app/
 ---> Using cache
 ---> a60478496159
Step 4/6 : RUN npm install
 ---> Using cache
 ---> 2ef20360480e
Step 5/6 : COPY . /app
 ---> e19b20dd0f4e
Step 6/6 : CMD ["npm", "start"]
 ---> Running in ac712dda1de1
Removing intermediate container ac712dda1de1
 ---> c73fed19d7f2

Successfully built c73fed19d7f2
Successfully tagged 5e-srd-api_api:latest
Attaching to 5e-srd-api_db_1, 5e-srd-api_api_1
db_1   | jq: error (at /tmp/docker-entrypoint-config.json:1): Cannot index string with string "systemLog"
db_1   | jq: error (at /tmp/docker-entrypoint-config.json:1): Cannot index string with string "net"
db_1   | 2020-01-25T18:27:52.797+0000 I  CONTROL  [main] Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'
api_1  | /usr/local/bin/docker-entrypoint.sh: exec: line 8: exec: not found
db_1   | 2020-01-25T18:27:52.799+0000 I  CONTROL  [initandlisten] MongoDB starting : pid=1 port=27017 dbpath=/data/db2 64-bit host=d52bcf9c1819
db_1   | 2020-01-25T18:27:52.799+0000 I  CONTROL  [initandlisten] db version v4.2.2
db_1   | 2020-01-25T18:27:52.799+0000 I  CONTROL  [initandlisten] git version: a0bbbff6ada159e19298d37946ac8dc4b497eadf
db_1   | 2020-01-25T18:27:52.799+0000 I  CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.1.1  11 Sep 2018
db_1   | 2020-01-25T18:27:52.799+0000 I  CONTROL  [initandlisten] allocator: tcmalloc
db_1   | 2020-01-25T18:27:52.799+0000 I  CONTROL  [initandlisten] modules: none
db_1   | 2020-01-25T18:27:52.799+0000 I  CONTROL  [initandlisten] build environment:
db_1   | 2020-01-25T18:27:52.799+0000 I  CONTROL  [initandlisten]     distmod: ubuntu1804
db_1   | 2020-01-25T18:27:52.799+0000 I  CONTROL  [initandlisten]     distarch: x86_64
db_1   | 2020-01-25T18:27:52.799+0000 I  CONTROL  [initandlisten]     target_arch: x86_64
db_1   | 2020-01-25T18:27:52.799+0000 I  CONTROL  [initandlisten] options: { config: "/etc/mongodb.conf", net: { bindIp: "*" }, storage: { dbPath: "/data/db2" } }
db_1   | 2020-01-25T18:27:52.799+0000 I  STORAGE  [initandlisten] Detected data files in /data/db2 created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
db_1   | 2020-01-25T18:27:52.799+0000 I  STORAGE  [initandlisten] 
db_1   | 2020-01-25T18:27:52.799+0000 I  STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
db_1   | 2020-01-25T18:27:52.799+0000 I  STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
db_1   | 2020-01-25T18:27:52.799+0000 I  STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=3344M,cache_overflow=(file_max=0M),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],
db_1   | 2020-01-25T18:27:53.702+0000 I  STORAGE  [initandlisten] WiredTiger message [1579976873:702934][1:0x7fd1d74adb00], txn-recover: Recovering log 3 through 4
db_1   | 2020-01-25T18:27:53.761+0000 I  STORAGE  [initandlisten] WiredTiger message [1579976873:761715][1:0x7fd1d74adb00], txn-recover: Recovering log 4 through 4
db_1   | 2020-01-25T18:27:53.832+0000 I  STORAGE  [initandlisten] WiredTiger message [1579976873:832741][1:0x7fd1d74adb00], txn-recover: Main recovery loop: starting at 3/4736 to 4/256
db_1   | 2020-01-25T18:27:53.922+0000 I  STORAGE  [initandlisten] WiredTiger message [1579976873:922488][1:0x7fd1d74adb00], txn-recover: Recovering log 3 through 4
db_1   | 2020-01-25T18:27:54.107+0000 I  STORAGE  [initandlisten] WiredTiger message [1579976874:107594][1:0x7fd1d74adb00], txn-recover: Recovering log 4 through 4
db_1   | 2020-01-25T18:27:54.164+0000 I  STORAGE  [initandlisten] WiredTiger message [1579976874:164317][1:0x7fd1d74adb00], txn-recover: Set global recovery timestamp: (0,0)
db_1   | 2020-01-25T18:27:54.714+0000 I  RECOVERY [initandlisten] WiredTiger recoveryTimestamp. Ts: Timestamp(0, 0)
db_1   | 2020-01-25T18:27:54.722+0000 I  STORAGE  [initandlisten] Timestamp monitor starting
db_1   | 2020-01-25T18:27:54.907+0000 I  CONTROL  [initandlisten] 
db_1   | 2020-01-25T18:27:54.907+0000 I  CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
db_1   | 2020-01-25T18:27:54.907+0000 I  CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
db_1   | 2020-01-25T18:27:54.907+0000 I  CONTROL  [initandlisten] 
db_1   | 2020-01-25T18:27:54.926+0000 I  SHARDING [initandlisten] Marking collection local.system.replset as collection version: <unsharded>
db_1   | 2020-01-25T18:27:54.928+0000 I  STORAGE  [initandlisten] Flow Control is enabled on this deployment.
db_1   | 2020-01-25T18:27:54.928+0000 I  SHARDING [initandlisten] Marking collection admin.system.roles as collection version: <unsharded>
db_1   | 2020-01-25T18:27:54.928+0000 I  SHARDING [initandlisten] Marking collection admin.system.version as collection version: <unsharded>
db_1   | 2020-01-25T18:27:54.929+0000 I  SHARDING [initandlisten] Marking collection local.startup_log as collection version: <unsharded>
db_1   | 2020-01-25T18:27:54.930+0000 I  FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db2/diagnostic.data'
db_1   | 2020-01-25T18:27:54.931+0000 I  SHARDING [LogicalSessionCacheRefresh] Marking collection config.system.sessions as collection version: <unsharded>
db_1   | 2020-01-25T18:27:54.931+0000 I  NETWORK  [initandlisten] Listening on /tmp/mongodb-27017.sock
db_1   | 2020-01-25T18:27:54.931+0000 I  NETWORK  [initandlisten] Listening on 0.0.0.0
db_1   | 2020-01-25T18:27:54.931+0000 I  SHARDING [LogicalSessionCacheReap] Marking collection config.transactions as collection version: <unsharded>
db_1   | 2020-01-25T18:27:54.931+0000 I  NETWORK  [initandlisten] waiting for connections on port 27017
db_1   | 2020-01-25T18:27:55.000+0000 I  SHARDING [ftdc] Marking collection local.oplog.rs as collection version: <unsharded>
5e-srd-api_api_1 exited with code 127
Gracefully stopping... (press Ctrl+C again to force)
Huge11 commented 4 years ago

I have the same problem

> Starting 5esrdapi_db_1 ... 
> Starting 5esrdapi_db_1 ... done
> Starting 5esrdapi_api_1 ... 
> Starting 5esrdapi_api_1 ... done
> Attaching to 5esrdapi_db_1, 5esrdapi_api_1
> db_1   | jq: error (at /tmp/docker-entrypoint-config.json:1): Cannot index string with string "systemLog"
> db_1   | jq: error (at /tmp/docker-entrypoint-config.json:1): Cannot index string with string "net"
> db_1   | 2020-01-31T02:13:59.675+0000 I  CONTROL  [main] Automatically disabling TLS 1.0, to force-enable TLS 1.0 specify --sslDisabledProtocols 'none'
> db_1   | 2020-01-31T02:13:59.681+0000 I  CONTROL  [initandlisten] MongoDB starting : pid=1 port=27017 dbpath=/data/db2 64-bit host=91d55619b14b
> db_1   | 2020-01-31T02:13:59.681+0000 I  CONTROL  [initandlisten] db version v4.2.2
> db_1   | 2020-01-31T02:13:59.681+0000 I  CONTROL  [initandlisten] git version: a0bbbff6ada159e19298d37946ac8dc4b497eadf
> db_1   | 2020-01-31T02:13:59.681+0000 I  CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.1.1  11 Sep 2018
> db_1   | 2020-01-31T02:13:59.681+0000 I  CONTROL  [initandlisten] allocator: tcmalloc
> db_1   | 2020-01-31T02:13:59.681+0000 I  CONTROL  [initandlisten] modules: none
> db_1   | 2020-01-31T02:13:59.681+0000 I  CONTROL  [initandlisten] build environment:
> db_1   | 2020-01-31T02:13:59.681+0000 I  CONTROL  [initandlisten]     distmod: ubuntu1804
> db_1   | 2020-01-31T02:13:59.681+0000 I  CONTROL  [initandlisten]     distarch: x86_64
> db_1   | 2020-01-31T02:13:59.681+0000 I  CONTROL  [initandlisten]     target_arch: x86_64
> db_1   | 2020-01-31T02:13:59.681+0000 I  CONTROL  [initandlisten] options: { config: "/etc/mongodb.conf", net: { bindIp: "*" }, storage: { dbPath: "/data/db2" } }
> db_1   | 2020-01-31T02:13:59.681+0000 I  STORAGE  [initandlisten] Detected data files in /data/db2 created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
> db_1   | 2020-01-31T02:13:59.682+0000 I  STORAGE  [initandlisten] 
> db_1   | 2020-01-31T02:13:59.682+0000 I  STORAGE  [initandlisten] ** WARNING: Using the XFS filesystem is strongly recommended with the WiredTiger storage engine
> db_1   | 2020-01-31T02:13:59.682+0000 I  STORAGE  [initandlisten] **          See http://dochub.mongodb.org/core/prodnotes-filesystem
> db_1   | 2020-01-31T02:13:59.682+0000 I  STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=3180M,cache_overflow=(file_max=0M),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],
> api_1  | /usr/local/bin/docker-entrypoint.sh: exec: line 8: exec: not found
> db_1   | 2020-01-31T02:14:00.281+0000 I  STORAGE  [initandlisten] WiredTiger message [1580436840:281765][1:0x7f0e925c5b00], txn-recover: Recovering log 4 through 5
> db_1   | 2020-01-31T02:14:00.339+0000 I  STORAGE  [initandlisten] WiredTiger message [1580436840:339887][1:0x7f0e925c5b00], txn-recover: Recovering log 5 through 5
> db_1   | 2020-01-31T02:14:00.447+0000 I  STORAGE  [initandlisten] WiredTiger message [1580436840:447251][1:0x7f0e925c5b00], txn-recover: Main recovery loop: starting at 4/4736 to 5/256
> 5esrdapi_api_1 exited with code 127
> db_1   | 2020-01-31T02:14:00.564+0000 I  STORAGE  [initandlisten] WiredTiger message [1580436840:564592][1:0x7f0e925c5b00], txn-recover: Recovering log 4 through 5
> db_1   | 2020-01-31T02:14:00.634+0000 I  STORAGE  [initandlisten] WiredTiger message [1580436840:634827][1:0x7f0e925c5b00], txn-recover: Recovering log 5 through 5
> db_1   | 2020-01-31T02:14:00.678+0000 I  STORAGE  [initandlisten] WiredTiger message [1580436840:678086][1:0x7f0e925c5b00], txn-recover: Set global recovery timestamp: (0,0)
> db_1   | 2020-01-31T02:14:00.701+0000 I  RECOVERY [initandlisten] WiredTiger recoveryTimestamp. Ts: Timestamp(0, 0)
> db_1   | 2020-01-31T02:14:00.722+0000 I  STORAGE  [initandlisten] Timestamp monitor starting
> db_1   | 2020-01-31T02:14:00.725+0000 I  CONTROL  [initandlisten] 
> db_1   | 2020-01-31T02:14:00.725+0000 I  CONTROL  [initandlisten] ** WARNING: Access control is not enabled for the database.
> db_1   | 2020-01-31T02:14:00.725+0000 I  CONTROL  [initandlisten] **          Read and write access to data and configuration is unrestricted.
> db_1   | 2020-01-31T02:14:00.725+0000 I  CONTROL  [initandlisten] 
> db_1   | 2020-01-31T02:14:00.747+0000 I  SHARDING [initandlisten] Marking collection local.system.replset as collection version: <unsharded>
> db_1   | 2020-01-31T02:14:00.750+0000 I  STORAGE  [initandlisten] Flow Control is enabled on this deployment.
> db_1   | 2020-01-31T02:14:00.750+0000 I  SHARDING [initandlisten] Marking collection admin.system.roles as collection version: <unsharded>
> db_1   | 2020-01-31T02:14:00.750+0000 I  SHARDING [initandlisten] Marking collection admin.system.version as collection version: <unsharded>
> db_1   | 2020-01-31T02:14:00.754+0000 I  SHARDING [initandlisten] Marking collection local.startup_log as collection version: <unsharded>
> db_1   | 2020-01-31T02:14:00.754+0000 I  FTDC     [initandlisten] Initializing full-time diagnostic data capture with directory '/data/db2/diagnostic.data'
> db_1   | 2020-01-31T02:14:00.756+0000 I  SHARDING [LogicalSessionCacheRefresh] Marking collection config.system.sessions as collection version: <unsharded>
> db_1   | 2020-01-31T02:14:00.756+0000 I  NETWORK  [initandlisten] Listening on /tmp/mongodb-27017.sock
> db_1   | 2020-01-31T02:14:00.756+0000 I  NETWORK  [initandlisten] Listening on 0.0.0.0
> db_1   | 2020-01-31T02:14:00.756+0000 I  NETWORK  [initandlisten] waiting for connections on port 27017
> db_1   | 2020-01-31T02:14:00.756+0000 I  SHARDING [LogicalSessionCacheReap] Marking collection config.transactions as collection version: <unsharded>
> db_1   | 2020-01-31T02:14:01.001+0000 I  SHARDING [ftdc] Marking collection local.oplog.rs as collection version: <unsharded>
> ^CGracefully stopping... (press Ctrl+C again to force)
> Stopping 5esrdapi_db_1 ... done
bagelbits commented 4 years ago

Woah. I'll take a look on that. That's weird.

bagelbits commented 4 years ago

Yeah. That's real weird. That would point to something potentially wrong here: https://github.com/bagelbits/5e-database/blob/master/Dockerfile

bagelbits commented 4 years ago

I also wonder if this is related to the fact that the docker image is running mongo:latest but I'm only using mongo:3.6.12

bagelbits commented 4 years ago

Also that's weird that this is happening:

api_1  | /usr/local/bin/docker-entrypoint.sh: exec: line 8: exec: not found
bagelbits commented 4 years ago

That's making me think that that's not related to mongo.

bagelbits commented 4 years ago

Okay. Figured it out. PR coming shortly.

bagelbits commented 4 years ago

@jtompkins84 @Huge11 Sorry it took me so long to notice this issue!

bagelbits commented 4 years ago

That should be fixed! Feel free to reopen if you're still having issues!

jtompkins84 commented 4 years ago

@bagelbits Thanks for looking into that. Just pulled the latest changes and it builds up fine now for me.