max_tries to be a configuration

[taboca]

I have a MacBook air 2013 — perhaps a bit loaded — and I am under the impression that the max_tries = 5 was not enough time which led to Mongo Express failing.

The max_tries variable I am referring to is: https://github.com/mongo-express/mongo-express-docker/blob/master/docker-entrypoint.sh#L11

When looking at my logs I can see that it may have reached out to the maximum:

Filtering the 'retrying' lines

tabocalabs.remotebot.mongo-express_1  | Wed Jan 20 20:27:07 UTC 2021 retrying to connect to tabocalabs.remotebot.mongo-express_1  | Wed Jan 20 20:27:08 UTC 2021 retrying to connect to tabocalabs.remotebot.mongo-express_1  | Wed Jan 20 20:27:09 UTC 2021 retrying to connect to tabocalabs.remotebot.mongo-express_1  | Wed Jan 20 20:27:10 UTC 2021 retrying to connect to 

Full log until the error

Creating network "remote-mongodb-stories_mongo-compose-network" with driver "bridge"
Creating remote-mongodb-stories_tabocalabs.remotebot.mongo_1 ... done
Creating remote-mongodb-stories_tabocalabs.remotebot.mongo-express_1 ... done
Attaching to remote-mongodb-stories_tabocalabs.remotebot.mongo_1, remote-mongodb-stories_tabocalabs.remotebot.mongo-express_1
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:04.986+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'"}
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:05.038+00:00"},"s":"W",  "c":"ASIO",     "id":22601,   "ctx":"main","msg":"No TransportLayer configured during NetworkInterface startup"}
tabocalabs.remotebot.mongo-express_1  | /docker-entrypoint.sh: connect: Connection refused
tabocalabs.remotebot.mongo-express_1  | /docker-entrypoint.sh: line 14: /dev/tcp/tabocalabs.remotebot.mongo/27017: Connection refused
tabocalabs.remotebot.mongo-express_1  | Waiting for tabocalabs.remotebot.mongo:27017...
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:05.041+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."}
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:05.061+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":"28aa4a326016"}}
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:05.061+00:00"},"s":"I",  "c":"CONTROL",  "id":23403,   "ctx":"initandlisten","msg":"Build Info","attr":{"buildInfo":{"version":"4.4.3","gitVersion":"913d6b62acfbb344dde1b116f4161360acd8fd13","openSSLVersion":"OpenSSL 1.1.1  11 Sep 2018","modules":[],"allocator":"tcmalloc","environment":{"distmod":"ubuntu1804","distarch":"x86_64","target_arch":"x86_64"}}}}
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:05.061+00:00"},"s":"I",  "c":"CONTROL",  "id":51765,   "ctx":"initandlisten","msg":"Operating System","attr":{"os":{"name":"Ubuntu","version":"18.04"}}}
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:05.061+00:00"},"s":"I",  "c":"CONTROL",  "id":21951,   "ctx":"initandlisten","msg":"Options set by command line","attr":{"options":{"net":{"bindIp":"*"},"security":{"authorization":"enabled"}}}}
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:05.093+00:00"},"s":"W",  "c":"STORAGE",  "id":22271,   "ctx":"initandlisten","msg":"Detected unclean shutdown - Lock file is not empty","attr":{"lockFile":"/data/db/mongod.lock"}}
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:05.156+00:00"},"s":"I",  "c":"STORAGE",  "id":22270,   "ctx":"initandlisten","msg":"Storage engine to use detected by data files","attr":{"dbpath":"/data/db","storageEngine":"wiredTiger"}}
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:05.181+00:00"},"s":"W",  "c":"STORAGE",  "id":22302,   "ctx":"initandlisten","msg":"Recovering data from the last clean checkpoint."}
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:05.186+00:00"},"s":"I",  "c":"STORAGE",  "id":22315,   "ctx":"initandlisten","msg":"Opening WiredTiger","attr":{"config":"create,cache_size=487M,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,compact_progress],"}}
tabocalabs.remotebot.mongo-express_1  | Wed Jan 20 20:27:07 UTC 2021 retrying to connect to tabocalabs.remotebot.mongo:27017 (2/5)
tabocalabs.remotebot.mongo-express_1  | /docker-entrypoint.sh: connect: Connection refused
tabocalabs.remotebot.mongo-express_1  | /docker-entrypoint.sh: line 14: /dev/tcp/tabocalabs.remotebot.mongo/27017: Connection refused
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:08.663+00:00"},"s":"E",  "c":"STORAGE",  "id":22435,   "ctx":"initandlisten","msg":"WiredTiger error","attr":{"error":95,"message":"[1611174428:663344][1:0x7f560c709ac0], connection: __posix_std_fallocate, 58: /data/db/journal/WiredTigerTmplog.0000000001: fallocate:: Operation not supported"}}
tabocalabs.remotebot.mongo_1          | {"t":{"$date":"2021-01-20T20:27:08.663+00:00"},"s":"E",  "c":"STORAGE",  "id":22435,   "ctx":"initandlisten","msg":"WiredTiger error","attr":{"error":95,"message":"[1611174428:663942][1:0x7f560c709ac0], connection: __posix_sys_fallocate, 75: /data/db/journal/WiredTigerTmplog.0000000001: fallocate:: Operation not supported"}}
tabocalabs.remotebot.mongo-express_1  | Wed Jan 20 20:27:08 UTC 2021 retrying to connect to tabocalabs.remotebot.mongo:27017 (3/5)
tabocalabs.remotebot.mongo-express_1  | /docker-entrypoint.sh: connect: Connection refused
tabocalabs.remotebot.mongo-express_1  | /docker-entrypoint.sh: line 14: /dev/tcp/tabocalabs.remotebot.mongo/27017: Connection refused
tabocalabs.remotebot.mongo-express_1  | /docker-entrypoint.sh: connect: Connection refused
tabocalabs.remotebot.mongo-express_1  | /docker-entrypoint.sh: line 14: /dev/tcp/tabocalabs.remotebot.mongo/27017: Connection refused
tabocalabs.remotebot.mongo-express_1  | Wed Jan 20 20:27:09 UTC 2021 retrying to connect to tabocalabs.remotebot.mongo:27017 (4/5)
tabocalabs.remotebot.mongo-express_1  | Wed Jan 20 20:27:10 UTC 2021 retrying to connect to tabocalabs.remotebot.mongo:27017 (5/5)
tabocalabs.remotebot.mongo-express_1  | /docker-entrypoint.sh: connect: Connection refused
tabocalabs.remotebot.mongo-express_1  | /docker-entrypoint.sh: line 14: /dev/tcp/tabocalabs.remotebot.mongo/27017: Connection refused
tabocalabs.remotebot.mongo-express_1  | Welcome to mongo-express
tabocalabs.remotebot.mongo-express_1  | ------------------------
tabocalabs.remotebot.mongo-express_1  | 
tabocalabs.remotebot.mongo-express_1  | 
tabocalabs.remotebot.mongo-express_1  | Mongo Express server listening at http://0.0.0.0:8081
tabocalabs.remotebot.mongo-express_1  | Server is open to allow connections from anyone (0.0.0.0)
tabocalabs.remotebot.mongo-express_1  | 
tabocalabs.remotebot.mongo-express_1  | /node_modules/mongodb/lib/server.js:265
tabocalabs.remotebot.mongo-express_1  |         process.nextTick(function() { throw err; })
tabocalabs.remotebot.mongo-express_1  |                                       ^
tabocalabs.remotebot.mongo-express_1  | Error [MongoError]: failed to connect to server [tabocalabs.remotebot.mongo:27017] on first connect
tabocalabs.remotebot.mongo-express_1  |     at Pool.<anonymous> (/node_modules/mongodb-core/lib/topologies/server.js:326:35)
tabocalabs.remotebot.mongo-express_1  |     at Pool.emit (events.js:314:20)
tabocalabs.remotebot.mongo-express_1  |     at Connection.<anonymous> (/node_modules/mongodb-core/lib/connection/pool.js:270:12)
tabocalabs.remotebot.mongo-express_1  |     at Object.onceWrapper (events.js:421:26)
tabocalabs.remotebot.mongo-express_1  |     at Connection.emit (events.js:314:20)
tabocalabs.remotebot.mongo-express_1  |     at Socket.<anonymous> (/node_modules/mongodb-core/lib/connection/connection.js:175:49)
tabocalabs.remotebot.mongo-express_1  |     at Object.onceWrapper (events.js:421:26)
tabocalabs.remotebot.mongo-express_1  |     at Socket.emit (events.js:314:20)
tabocalabs.remotebot.mongo-express_1  |     at emitErrorNT (internal/streams/destroy.js:92:8)
tabocalabs.remotebot.mongo-express_1  |     at emitErrorAndCloseNT (internal/streams/destroy.js:60:3)
remote-mongodb-stories_tabocalabs.remotebot.mongo-express_1 exited with code 1

After that "docker container ls" gave me only mongo, not mongo-express. Then I did again another "docker-compose" up, assuming it would only come up with what is not available, and then it worked. Thus I am assuming that "docker-compose" up on the second attempt brought express properly after mongo was up.

Suggestion

Wonder if makes sense this variable to be available as an environment variable. If it makes I wonder if the patch is simple. Would it be as simple as doing something like the following:

Existing code

    local max_tries=5 tries=1

Proposed code

    local max_tries=$ME_CONFIG_MONGODB_MAXTRIES tries=1 

[taboca]

It seems to be something else. I have forked https://github.com/taboca/mongo-express-docker changed the variable but didn't work.

[taboca]

All right — this is back on track. I believe that a lot of people are having the problem of "connection refused" when Mongo Express attempts to connect with Mongo using Docker compose because of the delay and max_tries which is not enough for many setups.

Today, when trying again, I have decided to use a larger max_tries (=30) and it worked and it's clear from the log that it was able to get through around >20 attempts:

tabocalabs.remotebot.mongo-express_1  | TABACON — Tue Jan 26 16:10:48 UTC 2021 retrying to connect to tabocalabs.remotebot.mongo:27017 (22/30)
tabocalabs.remotebot.mongo-express_1  | /docker-entrypoint.sh: connect: Connection refused

...

tabocalabs.remotebot.mongo-express_1  | TABACON — Tue Jan 26 16:10:49 UTC 2021 retrying to connect to tabocalabs.remotebot.mongo:27017 (23/30)

...

tabocalabs.remotebot.mongo-express_1  | Welcome to mongo-express
tabocalabs.remotebot.mongo-express_1  | ------------------------

Apologies for the "TABACON" at the logs. I added that to make sure it was my own image.

[taboca]

I am thinking about the following solution, that can be used from Docker Compose using environment variables:

    environment:
      ME_CONFIG_MONGODB_SERVER: tabocalabs.remotebot.mongo
      ME_CONFIG_MONGODB_SERVER_WAIT_MAX_TRIES: 30

Using the same prefix "ME_CONFIG_MONGODB_SERVER" to avoid confusion.