Bug 1009384

devenv_3921, met the issue frequently

Could reproduce this bug on INT

Result:
openshift@openshift-ubuntu:~/test$ rhc cartridge add -a etherpad -c mongodb-2.2 -l wsun+1
Adding mongodb-2.2 to application 'etherpad' ... exception: connect failed

Looks like this comes from the post install script which tries to configure mongodb.

The control script tries to wait up to 20 times for mongo to start by trying to connect to it.  Its unclear if the daemon fails to start completely or just takes a long time.

October 21 17:09:49 INFO Running post_install for 52657c9fea8f50e54d000007/mongodb

October 21 17:09:50 INFO Shell command '/sbin/runuser -s /bin/sh 52657c9fea8f50e54d000007 -c "exec /usr/bin/runcon 'unconfined_u:system_r:openshift_t:s0:c0,c1000' /bin/sh -c \"/var/lib/openshift/52657c9fea8f50e54d000007/mongodb/bin/post_install --version 2.2\""' ran. rc=1 out=MongoDB shell version: 2.4.6
connecting to: 127.1.244.2/test

Mon Oct 21 17:09:50.192 Error: couldn't connect to server 127.1.244.2:27017 at src/mongo/shell/mongo.js:147

Mongo eventually succeeds to start up.  There's no effective delay in the control script when its polling to see if mongodb has started which means the post_install script runs while mongo is still starting up.

The slow-down is due to creating the journal files, this appears to take 28 seconds - longer than the 20 second timeout baked in to the control hook.

There's a preallocateIsFaster test which takes around 4 seconds and is likely unnecessary on a cloud platform with unknown back-end storage.

Mon Oct 21 18:04:22.440 [initandlisten] preallocateIsFaster check took 4.107 secs

Mon Oct 21 18:04:22.440 [initandlisten] preallocating a journal file /var/lib/openshift/5265a4c9ea8f50e54d000145/mongodb/data/journal/prealloc.0

Mon Oct 21 18:04:31.622 [initandlisten] preallocating a journal file /var/lib/openshift/5265a4c9ea8f50e54d000145/mongodb/data/journal/prealloc.1

Mon Oct 21 18:04:41.171 [initandlisten] preallocating a journal file /var/lib/openshift/5265a4c9ea8f50e54d000145/mongodb/data/journal/prealloc.2

Mon Oct 21 18:04:50.576 [FileAllocator] allocating new datafile /var/lib/openshift/5265a4c9ea8f50e54d000145/mongodb/data/local.ns, filling with zeroes...


Unpacking the journal from a tar file (eg: from the install hook) seems to take less than 5 seconds on my devenv and eliminates 32 seconds of start lag.

Filed a new bug to track the slowness issue.


Until that's resolved, increased the timeout for mongodb.
https://github.com/openshift/origin-server/pull/3948

Commit pushed to master at https://github.com/openshift/origin-server

https://github.com/openshift/origin-server/commit/293c20c42fa82d56c1284e3af3828ebce2fe9b60
Bug 1009384 - it was observed that mongodb now preallocates the journal which takes over 30 seconds.

test on devenv_3927, mongodb can add normally.

[root@Daphne test]# rhc cartridge add -a mypython331 -c mongodb-2.2
Adding mongodb-2.2 to application 'mypython331' ... done

mongodb-2.2 (MongoDB 2.2)
-------------------------
  Gears:          Located with python-3.3
  Connection URL: mongodb://$OPENSHIFT_MONGODB_DB_HOST:$OPENSHIFT_MONGODB_DB_PORT/
  Database Name:  mypython331
  Password:       ewHvz1FD51bz
  Username:       admin

MongoDB 2.2 database added.  Please make note of these credentials:

   Root User:     admin
   Root Password: ewHvz1FD51bz
   Database Name: mypython331

Connection URL: mongodb://$OPENSHIFT_MONGODB_DB_HOST:$OPENSHIFT_MONGODB_DB_PORT/

move bug to verified