4

I keep getting exception in initAndListen: 98 Unable to lock file: /data/db/mongod.lock Resource temporarily unavailable. Is a mongod instance already running?, terminating upon a new deploy of MongoDB on OpenShift. The container is based on mongo:3.4 and /data/db is mounted as volume.

I've tried to remove /data/db/mongod.lock as suggested by What is the use of the mongo.lock file?. Doesn't help - now I get errors concerning WiredTiger.

Any idea how to make this work?

EDIT

Here's log of what's wrong after removing /data/db/mongod.lock

2019-03-15T12:34:48.948+0000 I -        [initandlisten] Detected data files in /data/db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2019-03-15T12:34:48.949+0000 I STORAGE  [initandlisten] Detected WT journal files.  Running recovery from last checkpoint.
2019-03-15T12:34:48.950+0000 I STORAGE  [initandlisten] journal to nojournal transition config: create,cache_size=31644M,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),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),verbose=(recovery_progress),
2019-03-15T12:34:48.955+0000 E STORAGE  [initandlisten] WiredTiger error (11) [1552653288:955084][8:0x7f91ef9a9d40], wiredtiger_open: /data/db/WiredTiger.lock: handle-lock: fcntl: Resource temporarily unavailable
2019-03-15T12:34:48.955+0000 E STORAGE  [initandlisten] WiredTiger error (16) [1552653288:955157][8:0x7f91ef9a9d40], wiredtiger_open: WiredTiger database is already being managed by another process: Device or resource busy
2019-03-15T12:34:48.957+0000 I -        [initandlisten] Assertion: 28718:16: Device or resource busy src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp 254
2019-03-15T12:34:48.971+0000 I STORAGE  [initandlisten] exception in initAndListen: 28718 16: Device or resource busy, terminating
2019-03-15T12:34:48.971+0000 I NETWORK  [initandlisten] shutdown: going to close listening sockets...
2019-03-15T12:34:48.971+0000 I NETWORK  [initandlisten] removing socket file: /tmp/mongodb-27017.sock
2019-03-15T12:34:48.971+0000 I NETWORK  [initandlisten] shutdown: going to flush diaglog...
2019-03-15T12:34:48.971+0000 I CONTROL  [initandlisten] now exiting
2019-03-15T12:34:48.971+0000 I CONTROL  [initandlisten] shutting down with code:100

And here's the MongoDB container config

- image: 'mongo:3.4'
  command:
    - sh
  args:
    - '-c'
    - rm -f /data/db/mongod.lock; mongod --dbpath /data/db --repair; mongod --dbpath /data/db
  volumeMounts:
    - mountPath: /data/db

EDIT 2

First off, read this to understand how OpenShift terminates containers https://pracucci.com/graceful-shutdown-of-kubernetes-pods.html.

I've removed everything in /data/db and then updated container config

- image: 'mongo:3.4'
  command:
    - /bin/bash
  args:
    - '-c'
    - rm -f /data/db/mongod.lock /data/db/WiredTiger.lock; mongod
  volumeMounts:
    - mountPath: /data/db

All of a number of test deploys were successful. And after a couple more deploys it started failing again, this time with

2019-03-15T14:25:05.657+0000 I CONTROL  [initandlisten] MongoDB starting : pid=8 port=27017 dbpath=/data/db 64-bit host=kx-api-staging-105-tbbh2
2019-03-15T14:25:05.657+0000 I CONTROL  [initandlisten] db version v3.4.19
2019-03-15T14:25:05.657+0000 I CONTROL  [initandlisten] git version: a2d97db8fe449d15eb8e275bbf318491781472bf
2019-03-15T14:25:05.657+0000 I CONTROL  [initandlisten] OpenSSL version: OpenSSL 1.0.1t  3 May 2016
2019-03-15T14:25:05.657+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2019-03-15T14:25:05.657+0000 I CONTROL  [initandlisten] modules: none
2019-03-15T14:25:05.657+0000 I CONTROL  [initandlisten] build environment:
2019-03-15T14:25:05.657+0000 I CONTROL  [initandlisten]     distmod: debian81
2019-03-15T14:25:05.657+0000 I CONTROL  [initandlisten]     distarch: x86_64
2019-03-15T14:25:05.657+0000 I CONTROL  [initandlisten]     target_arch: x86_64
2019-03-15T14:25:05.657+0000 I CONTROL  [initandlisten] options: {}
2019-03-15T14:25:05.726+0000 I -        [initandlisten] Detected data files in /data/db created by the 'wiredTiger' storage engine, so setting the active storage engine to 'wiredTiger'.
2019-03-15T14:25:05.727+0000 I STORAGE  [initandlisten] wiredtiger_open config: create,cache_size=31644M,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),checkpoint=(wait=60,log_size=2GB),statistics_log=(wait=0),verbose=(recovery_progress),
2019-03-15T14:25:05.785+0000 E STORAGE  [initandlisten] WiredTiger error (-31802) [1552659905:785255][8:0x7f1fb8b33d40], file:WiredTiger.wt, connection: unable to read root page from file:WiredTiger.wt: WT_ERROR: non-specific WiredTiger error
2019-03-15T14:25:05.785+0000 E STORAGE  [initandlisten] WiredTiger error (0) [1552659905:785313][8:0x7f1fb8b33d40], file:WiredTiger.wt, connection: WiredTiger has failed to open its metadata
2019-03-15T14:25:05.785+0000 E STORAGE  [initandlisten] WiredTiger error (0) [1552659905:785324][8:0x7f1fb8b33d40], file:WiredTiger.wt, connection: This may be due to the database files being encrypted, being from an older version or due to corruption on disk
2019-03-15T14:25:05.785+0000 E STORAGE  [initandlisten] WiredTiger error (0) [1552659905:785336][8:0x7f1fb8b33d40], file:WiredTiger.wt, connection: You should confirm that you have opened the database with the correct options including all encryption and compression options
2019-03-15T14:25:05.789+0000 I -        [initandlisten] Assertion: 28595:-31802: WT_ERROR: non-specific WiredTiger error src/mongo/db/storage/wiredtiger/wiredtiger_kv_engine.cpp 277
2019-03-15T14:25:05.805+0000 I STORAGE  [initandlisten] exception in initAndListen: 28595 -31802: WT_ERROR: non-specific WiredTiger error, terminating
2019-03-15T14:25:05.805+0000 I NETWORK  [initandlisten] shutdown: going to close listening sockets...
2019-03-15T14:25:05.805+0000 I NETWORK  [initandlisten] removing socket file: /tmp/mongodb-27017.sock
2019-03-15T14:25:05.805+0000 I NETWORK  [initandlisten] shutdown: going to flush diaglog...
2019-03-15T14:25:05.805+0000 I CONTROL  [initandlisten] now exiting
2019-03-15T14:25:05.805+0000 I CONTROL  [initandlisten] shutting down with code:100
Dušan Maďar
  • 9,269
  • 5
  • 49
  • 64

1 Answers1

0

In my case tt fails with the message: IllegalOperation: Attempted to create a lock file on a read-only directory: /data/db

elrrorLog: {"t":{"$date":"2020-10-22T14:37:32.346+00: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":"2020-10-22T14:37:32.349+00:00"},"s":"W", "c":"ASIO", "id":22601, "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"} {"t":{"$date":"2020-10-22T14:37:32.349+00:00"},"s":"I", "c":"NETWORK", "id":4648601, "ctx":"main","msg":"Implicit TCP FastOpen unavailable. If TCP FastOpen is required, set tcpFastOpenServer, tcpFastOpenClient, and tcpFastOpenQueueSize."} {"t":{"$date":"2020-10-22T14:37:32.349+00:00"},"s":"I", "c":"STORAGE", "id":4615611, "ctx":"initandlisten","msg":"MongoDB starting","attr":{"pid":1,"port":27017,"dbPath":"/data/db","architecture":"64-bit","host":"my-AppMgr-mongo-6c8c84d5d9-n52nt"}} {"t":{"$date":"2020-10-22T14:37:32.349+00:00"},"s":"I", "c":"CONTROL", "id":23403, "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"4.4.1","gitVersion":"ad91a93a5a31e175f5cbf8c69561e788bbc55ce1","openSSLVersion":"OpenSSL 1.1.1 11 Sep 2018","modules":[],"allocator":"tcmalloc","environment":{"distmod":"ubuntu1804","distarch":"x86_64","target_arch":"x86_64"}}}} {"t":{"$date":"2020-10-22T14:37:32.349+00:00"},"s":"I", "c":"CONTROL", "id":51765, "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Ubuntu","version":"18.04"}}} {"t":{"$date":"2020-10-22T14:37:32.350+00:00"},"s":"I", "c":"CONTROL", "id":21951, "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"net":{"bindIp":""}}}} {"t":{"$date":"2020-10-22T14:37:32.351+00:00"},"s":"E", "c":"STORAGE", "id":20557, "ctx":"initandlisten","msg":"DBException in initAndListen, terminating","attr":{"error":"IllegalOperation: Attempted to create a lock file on a read-only directory: /data/db"}}* {"t":{"$date":"2020-10-22T14:37:32.351+00:00"},"s":"I", "c":"REPL", "id":4784900, "ctx":"initandlisten","msg":"Stepping down the ReplicationCoordinator for shutdown","attr":{"waitTimeMillis":10000}} {"t":{"$date":"2020-10-22T14:37:32.351+00:00"},"s":"I", "c":"COMMAND", "id":4784901, "ctx":"initandlisten","msg":"Shutting down the MirrorMaestro"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"SHARDING", "id":4784902, "ctx":"initandlisten","msg":"Shutting down the WaitForMajorityService"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"NETWORK", "id":20562, "ctx":"initandlisten","msg":"Shutdown: going to close listening sockets"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"NETWORK", "id":4784905, "ctx":"initandlisten","msg":"Shutting down the global connection pool"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"STORAGE", "id":4784906, "ctx":"initandlisten","msg":"Shutting down the FlowControlTicketholder"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"-", "id":20520, "ctx":"initandlisten","msg":"Stopping further Flow Control ticket acquisitions."} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"NETWORK", "id":4784918, "ctx":"initandlisten","msg":"Shutting down the ReplicaSetMonitor"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"SHARDING", "id":4784921, "ctx":"initandlisten","msg":"Shutting down the MigrationUtilExecutor"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"CONTROL", "id":4784925, "ctx":"initandlisten","msg":"Shutting down free monitoring"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"FTDC", "id":4784926, "ctx":"initandlisten","msg":"Shutting down full-time data capture"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"STORAGE", "id":4784927, "ctx":"initandlisten","msg":"Shutting down the HealthLog"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"STORAGE", "id":4784929, "ctx":"initandlisten","msg":"Acquiring the global lock for shutdown"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"-", "id":4784931, "ctx":"initandlisten","msg":"Dropping the scope cache for shutdown"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"CONTROL", "id":20565, "ctx":"initandlisten","msg":"Now exiting"} {"t":{"$date":"2020-10-22T14:37:32.352+00:00"},"s":"I", "c":"CONTROL", "id":23138, "ctx":"initandlisten","msg":"Shutting down","attr":{"exitCode":100}}

Sanjeev
  • 375
  • 1
  • 3
  • 14