[SERVER-10064] How does MMS know the version number of my mongod server? Created: 29/Jun/13  Updated: 10/Dec/14  Resolved: 30/Jun/13

Status: Closed
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: None

Type: Question Priority: Trivial - P5
Reporter: Tom Laramee Assignee: Unassigned
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

CentOS x86_64, mongod 2.2.1.


Participants:

 Description   

I have 5 mongo servers in a replica set: zuemongo1, 2, 5, 6, and 7.

MMS currently shows their versions as 2.2.1, 2.2.5, 2.2.1, 2.2.5, 2.2.5 (respectively).

The active daemon running on all five servers is 2.2.1.

Last night, I did some maintenance on this replicaset, and so knowing (a) I was going to bounce the dameon on each server and (b) we need to upgrade to 2.2.5 soon, I took last night as an opportunity to get the 2.2.5 binaries on the servers, but set them aside (details below) so i can upgrade and downgrade at will (details below) when we're ready for the upgrade.

What's odd is that MMS thinks we're running 2.2.5 on 3 servers and 2.2.1 on 2 servers ... when in reality i executed the exact same commands on all five servers.

Yesterday, I stopped mongod:
$ /etc/init.d/mongod stop

Yum upgraded to 2.2.5:
$ yum update mongo-10gen-2.2.5 mongo-10gen-server-2.2.5

But then mv'd all of the 2.2.5 binaries aside, e.g.:
$ cd /usr/bin
$ mv mongo mongo.2.2.5
$ mv mongod mongod.2.2.5
$ mv mongodump mongodump.2.2.5
$ mv mongoexport mongoexport.2.2.5
$ mv mongofiles mongofiles.2.2.5
$ mv mongoimport mongoimport.2.2.5
$ mv mongooplog mongooplog.2.2.5
$ mv mongoperf mongoperf.2.2.5
$ mv mongorestore mongorestore.2.2.5
$ mv mongos mongos.2.2.5
$ mv mongostat mongostat.2.2.5
$ mv mongotop mongotop.2.2.5
$ mv bsondump bsondump.2.2.5

And sym linkd the 2.2.1 binaries (which is what we've been running on):
$ ln -sf mongo.2.2.1 mongo
$ ln -sf mongod.2.2.1 mongod
$ ln -sf mongodump.2.2.1 mongodump
$ ln -sf mongoexport.2.2.1 mongoexport
$ ln -sf mongofiles.2.2.1 mongofiles
$ ln -sf mongoimport.2.2.1 mongoimport
$ ln -sf mongooplog.2.2.1 mongoimport
$ ln -sf mongoperf.2.2.1 mongoperf
$ ln -sf mongorestore.2.2.1 mongorestore
$ ln -sf mongos.2.2.1 mongos
$ ln -sf mongostat.2.2.1 mongostat
$ ln -sf mongotop.2.2.1 mongotop
$ ln -sf bsondump.2.2.1 bsondump

Then started mongod back up:
$ /etc/init.d/mongod start

So my incredibly trivial question is: how does MMS get it's version info? I'm guessing it's not from the running daemon but possibly via a YUM post-install hook or some YUM meta-data somewhere.

Thanks
--tom



 Comments   
Comment by Tom Laramee [ 01/Jul/13 ]

Johan: (cont)

The fact that the conditional restarts STDOUT & STDERR goes to /dev/null is bad idea. I have seen this before it's a bad idea in the other places too. (i've seen it in some /etc/init.d scripts)

The down side here is that I might miss the fact that the conditional restart failed.

The upside is none.

If you guys insist on a restart, it would be better to note the result of that signal going to the daemon and display an error when it fails.

Also, a:

echo "*** HEAD'S UP - RESTARING THE DAMEON ****"

would be wickedly helpful.

Comment by Tom Laramee [ 01/Jul/13 ]

Johan:

Whether this is a "standard" or not (it isn't), is a moot point.

The salient question here is: is this the right behavior for mongodb?

I'd like to make the case that it's not.

The problem is, the yum script is conflating two things:
(1) when i upgrade
(2) when i have a service-related outage due to a bounced daemon

This means that the time yum takes to go out and update it's repo meta-data, copy the rpm to my server, unpack it, and run all of the pre/post-install instructions (step 1) becomes automatically part of (2) my service interruption.

My goal is always to minimize the duration of (2), and this makes it impossible to do so.

I have two possible ways to update:
(1a) stop mongod
(1b) run a yum update
(1c) start mongod manually

vs:
(2a) run a yum update
(2b) have mongod restarted via a conditional restart compliments of yum

In both of those cases, the time of the "yum update" is part of my outage, and that is the core problem.

It would be much better if the yum update simply echo'd to STDOUT:

        • RUN A SERVICE RESTART TO BEGIN RUNNING THE NEW BINARY ****

That way, I could get the binaries on my machine, check out my configs, run a mongodump, and then bounce the daemon.

Comment by Johan Hedin [ 30/Jun/13 ]

Tom, restarting running deamons after an yum update is very common (I would say standard) on RedHat based distributions and mongodb is no different in that aspect.

Whats not considered good practice is to start a deamon that is stopped when you yum update.

Comment by Tom Laramee [ 30/Jun/13 ]

thanks Johan... at least i understand what happened.

so a couple of things:

(1) never have i encountered a software package in which a "yum update" causes
an active daemon to restart. i've installed hundreds of software packages
using yum and have never encountered this before.

(2) in reading various tutorials on upgrading mongo in yum (found using google),
i think everyone else is not expecting this either. everyone seems to indicate
that the last step is always a "service mongod start" or an "/etc/init.d/mongod start".

E.g.:
http://ivanfioravanti.wordpress.com/2013/03/19/upgrade-a-standalone-mongodb-2-2-to-2-4-on-linux-centos-in-azure/

(3) why does the postun section redirect stdout & stderr to /dev/null? what
makes this so confusing is that there are 2 lines of stdout when you run
an "/etc/init.d/mongod start" indicating that the daemon has started and
where the log can be found... these are buried in update script.

here's the 5 lines of the postun command i'm referencing:

%postun server
if test $1 -ge 1
then
/sbin/service mongod condrestart >/dev/null 2>&1 || :
fi

Comment by Johan Hedin [ 30/Jun/13 ]

tlaramee, when looking at the spec-file in the git repository for 2.2 it does a condrestart of mongod after an upgrade: https://github.com/mongodb/mongo/blob/v2.2/rpm/mongo.spec

The check for a running mongod in condrestart is a little bit simple: https://github.com/mongodb/mongo/blob/v2.2/rpm/init.d-mongod so if you for example have a stale /var/lock/subsys/mongod an yum update will start up a mongod directly after the update even if you don't have any mongod running.

Comment by Tom Laramee [ 30/Jun/13 ]

One possible explanation for this could be if this command:

$ yum update mongo-10gen-2.2.5 mongo-10gen-server-2.2.5

..caused the new binaries to be pulled down and a new daemon started in the background.

Is it possible that this was what happened?

That would explain the spawning of three 2.2.5 daemons. Then, when I manually tried to start them after the yum update via:

$ /etc/init.d/mongod start

These likely would have errored out due to an already-running daemon.

This would explain a lot if it's true.

Comment by Tom Laramee [ 30/Jun/13 ]

While we're at it: if the installer could not overwrite the existing binaries: THAT WOULD BE AMAZING!

Check out my initial comments - i'm maintaining multiple versions of your binaries so i can upgrade and downgrade at will - mostly to mitigate any risk w/ upgrading and running into a major production issue and having to roll back.

Comment by Tom Laramee [ 30/Jun/13 ]

The bug is that MMS seems to never downgrade a version.

I'm relatively confident that the daemons for all of these machines were started using v2.2.1.

Two things I don't understand are:

(1) this bug
(2) why the daemon seems to auto-restart following a yum upgrade.

w/r/t (2): I didn't manually restart the daemon during the yum upgrade – this was something the yum post-install script must have done on my behalf.

This is a HUGE problem for me ...and likely for others.

When I upgraded the server, the daemon was STOPPED. If yum is going to restart it on my behalf: this is bad ... it's really bad.

Said another way: at no point did I explicitly start a 2.2.5 daemon – i only started 2.2.1 daemons ... and there is no scenario in which I wanted a 2.2.5 daemon started.

I want to retain the choice to upgrade and downgrade at will - and so I "yum installed" the new binaries knowing i would set them aside (via a "mv").. then sym link the active binary.

Should the case arise that I need to roll-back, it's as simple as re-sym-linking and bouncing daemons.

Comment by Tom Laramee [ 30/Jun/13 ]

Here's mongo7 .. same deal - a restart on 2.2.5 followed by a downgrade to 2.2.1. MMS has the wrong version info.

[root@zuemongo7 mongo]# grep -A 20 "SERVER RESTARTED" 29

          • SERVER RESTARTED *****

Fri Jun 28 19:59:45 [initandlisten] MongoDB starting : pid=32512 port=27022 dbpath=/var/lib/mongo 64-bit host=zuemongo7.zulily.com
Fri Jun 28 19:59:45 [initandlisten] db version v2.2.5, pdfile version 4.5
Fri Jun 28 19:59:45 [initandlisten] git version: 14d8c4d1eb320ab10c6956f6e4b52263249bc0b4
Fri Jun 28 19:59:45 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
Fri Jun 28 19:59:45 [initandlisten] options:

{ config: "/etc/mongod.conf", dbpath: "/var/lib/mongo", fork: "true", logappend: "true", logpath: "/var/log/mongo/mongod.log", oplogSize: 5000, port: 27022, replSet: "zumongous", rest: "true" }

Fri Jun 28 19:59:45 [initandlisten] journal dir=/var/lib/mongo/journal
Fri Jun 28 19:59:45 [initandlisten] recover : no journal files present, no recovery needed
Fri Jun 28 19:59:46 [initandlisten] preallocateIsFaster=true 11.62
Fri Jun 28 19:59:47 [initandlisten] preallocateIsFaster=true 10.46
Fri Jun 28 19:59:48 [initandlisten] preallocateIsFaster=true 10.68
Fri Jun 28 19:59:48 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.0
Fri Jun 28 19:59:58 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.1
Fri Jun 28 20:00:08 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.2
Fri Jun 28 20:00:17 [initandlisten] waiting for connections on port 27022
Fri Jun 28 20:00:17 [websvr] admin web console waiting for connections on port 28022
Fri Jun 28 20:00:17 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
Fri Jun 28 20:00:17 [rsStart] replSet info you may need to run replSetInitiate – rs.initiate() in the shell – if that is not already done
Fri Jun 28 20:00:17 [initandlisten] connection accepted from 172.16.0.187:48315 #1 (1 connection now open)

          • SERVER RESTARTED *****

Fri Jun 28 20:00:39 [initandlisten] MongoDB starting : pid=8520 port=27022 dbpath=/var/lib/mongo 64-bit host=zuemongo7.zulily.com
Fri Jun 28 20:00:39 [initandlisten] db version v2.2.1, pdfile version 4.5
Fri Jun 28 20:00:39 [initandlisten] git version: d6764bf8dfe0685521b8bc7b98fd1fab8cfeb5ae
Fri Jun 28 20:00:39 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
Fri Jun 28 20:00:39 [initandlisten] options:

{ config: "/etc/mongod.conf", dbpath: "/var/lib/mongo", fork: "true", logappend: "true", logpath: "/var/log/mongo/mongod.log", oplogSize: 5000, port: 27022, replSet: "zumongous", rest: "true" }

Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.186:15324 #8027 (429 connections now open)
Fri Jun 28 20:00:39 [conn7828] end connection 172.16.0.186:12697 (428 connections now open)
Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.186:15396 #8028 (429 connections now open)
Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.136:51656 #8029 (430 connections now open)
Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.187:12492 #8030 (431 connections now open)
Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.182:51631 #8031 (432 connections now open)
Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.187:12510 #8032 (433 connections now open)
Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.136:51708 #8033 (434 connections now open)
Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.136:51730 #8034 (435 connections now open)
Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.136:51737 #8035 (436 connections now open)
Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.137:32510 #8036 (437 connections now open)
Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.186:15498 #8037 (438 connections now open)
Fri Jun 28 20:00:39 [initandlisten] connection accepted from 172.16.0.182:51678 #8038 (439 connections now open)

Comment by Tom Laramee [ 30/Jun/13 ]

Here's mongo6.

I reports it's on v2.2.5 ... even though the last restart is on v.2.2.1. I think the version info on MMS is wrong:

[root@zuemongo6 mongo]# grep -A 20 "ERVER RESTARTE" 29

          • SERVER RESTARTED *****

Fri Jun 28 20:23:25 [initandlisten] MongoDB starting : pid=4677 port=27021 dbpath=/var/lib/mongo 64-bit host=zuemongo6.zulily.com
Fri Jun 28 20:23:25 [initandlisten] db version v2.2.5, pdfile version 4.5
Fri Jun 28 20:23:25 [initandlisten] git version: 14d8c4d1eb320ab10c6956f6e4b52263249bc0b4
Fri Jun 28 20:23:25 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
Fri Jun 28 20:23:25 [initandlisten] options:

{ config: "/etc/mongod.conf", dbpath: "/var/lib/mongo", fork: "true", logappend: "true", logpath: "/var/log/mongo/mongod.log", oplogSize: 5000, port: 27021, replSet: "zumongous", rest: "true" }

Fri Jun 28 20:23:25 [initandlisten] journal dir=/var/lib/mongo/journal
Fri Jun 28 20:23:25 [initandlisten] recover : no journal files present, no recovery needed
Fri Jun 28 20:23:26 [initandlisten] preallocateIsFaster=true 13.72
Fri Jun 28 20:23:27 [initandlisten] preallocateIsFaster=true 13.28
Fri Jun 28 20:23:29 [initandlisten] preallocateIsFaster=true 13.6
Fri Jun 28 20:23:29 [initandlisten] preallocateIsFaster check took 3.367 secs
Fri Jun 28 20:23:29 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.0
Fri Jun 28 20:23:39 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.1
Fri Jun 28 20:23:49 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.2
Fri Jun 28 20:23:58 [initandlisten] waiting for connections on port 27021
Fri Jun 28 20:23:58 [websvr] admin web console waiting for connections on port 28021
Fri Jun 28 20:23:58 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
Fri Jun 28 20:23:58 [rsStart] replSet info you may need to run replSetInitiate – rs.initiate() in the shell – if that is not already done

          • SERVER RESTARTED *****

Fri Jun 28 20:24:14 [initandlisten] MongoDB starting : pid=12277 port=27021 dbpath=/var/lib/mongo 64-bit host=zuemongo6.zulily.com
Fri Jun 28 20:24:14 [initandlisten] db version v2.2.1, pdfile version 4.5
Fri Jun 28 20:24:14 [initandlisten] git version: d6764bf8dfe0685521b8bc7b98fd1fab8cfeb5ae
Fri Jun 28 20:24:14 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
Fri Jun 28 20:24:14 [initandlisten] options:

{ config: "/etc/mongod.conf", dbpath: "/var/lib/mongo", fork: "true", logappend: "true", logpath: "/var/log/mongo/mongod.log", oplogSize: 5000, port: 27021, replSet: "zumongous", rest: "true" }

Fri Jun 28 20:24:14 [initandlisten] connection accepted from 172.16.0.187:57117 #7369 (176 connections now open)
Fri Jun 28 20:24:14 [initandlisten] connection accepted from 172.16.0.181:54047 #7370 (177 connections now open)
Fri Jun 28 20:24:14 [initandlisten] connection accepted from 172.16.0.137:31161 #7371 (178 connections now open)
Fri Jun 28 20:24:14 [initandlisten] connection accepted from 172.16.0.137:31174 #7372 (179 connections now open)
Fri Jun 28 20:24:15 [initandlisten] connection accepted from 172.16.0.181:54088 #7373 (180 connections now open)
Fri Jun 28 20:24:15 [initandlisten] connection accepted from 172.16.0.137:31221 #7374 (181 connections now open)
Fri Jun 28 20:24:15 [initandlisten] connection accepted from 172.16.0.136:54817 #7375 (182 connections now open)
Fri Jun 28 20:24:15 [initandlisten] connection accepted from 172.16.0.182:12872 #7376 (183 connections now open)
Fri Jun 28 20:24:15 [initandlisten] connection accepted from 172.16.0.181:54112 #7377 (184 connections now open)
Fri Jun 28 20:24:15 [initandlisten] connection accepted from 172.16.0.186:31406 #7378 (185 connections now open)
Fri Jun 28 20:24:15 [initandlisten] connection accepted from 172.16.0.186:31424 #7379 (186 connections now open)
Fri Jun 28 20:24:15 [initandlisten] connection accepted from 172.16.0.186:31433 #7380 (187 connections now open)
Fri Jun 28 20:24:15 [initandlisten] connection accepted from 172.16.0.187:57330 #7381 (188 connections now open)
[root@zuemongo6 mongo]#

Comment by Tom Laramee [ 30/Jun/13 ]

Here's mongo5 .. this one had some serious problems connecting to the replica set ... so i ended up killing the active daemons manually and restarting. I can open a separate ticket for that bug if you'd like.

The salient restart is the last one – it's 2.2.1.

MMS reports this as 2.2.1 ... which makes sense to me, the last time the daemon was restarted was on v2.2.1 .. even though it had a previous restart on v2.2.5.

[root@zuemongo5 mongo]# grep -A 20 "SERVER RESTARTED" 29

          • SERVER RESTARTED *****

Fri Jun 28 20:31:24 [initandlisten] MongoDB starting : pid=11329 port=27020 dbpath=/var/lib/mongo 64-bit host=zuemongo5.zulily.com
Fri Jun 28 20:31:24 [initandlisten] db version v2.2.5, pdfile version 4.5
Fri Jun 28 20:31:24 [initandlisten] git version: 14d8c4d1eb320ab10c6956f6e4b52263249bc0b4
Fri Jun 28 20:31:24 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
Fri Jun 28 20:31:24 [initandlisten] options:

{ config: "/etc/mongod.conf", dbpath: "/var/lib/mongo", fork: "true", logappend: "true", logpath: "/var/log/mongo/mongod.log", oplogSize: 5000, port: 27020, replSet: "zumongous", rest: "true" }

Fri Jun 28 20:31:24 [initandlisten] journal dir=/var/lib/mongo/journal
Fri Jun 28 20:31:24 [initandlisten] recover : no journal files present, no recovery needed
Fri Jun 28 20:31:24 [initandlisten] preallocateIsFaster=true 7.68
Fri Jun 28 20:31:25 [initandlisten] preallocateIsFaster=true 8.04
Fri Jun 28 20:31:26 [initandlisten] preallocateIsFaster=true 8.2
Fri Jun 28 20:31:26 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.0
Fri Jun 28 20:31:32 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.1
Fri Jun 28 20:31:38 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.2
Fri Jun 28 20:31:45 [initandlisten] waiting for connections on port 27020
Fri Jun 28 20:31:45 [websvr] admin web console waiting for connections on port 28020
Fri Jun 28 20:31:45 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
Fri Jun 28 20:31:45 [rsStart] replSet info you may need to run replSetInitiate – rs.initiate() in the shell – if that is not already done
Fri Jun 28 20:31:45 [initandlisten] connection accepted from 172.16.0.187:46702 #1 (1 connection now open)

          • SERVER RESTARTED *****

Fri Jun 28 20:32:10 [initandlisten] connection accepted from 172.16.0.181:44536 #23773 (774 connections now open)
Fri Jun 28 20:32:10 [conn23634] end connection 172.16.0.20:45439 (773 connections now open)
Fri Jun 28 20:32:11 [initandlisten] connection accepted from 172.16.0.182:26782 #23774 (774 connections now open)
Fri Jun 28 20:32:11 [conn23608] end connection 172.16.0.18:34977 (773 connections now open)
Fri Jun 28 20:32:12 [initandlisten] connection accepted from 172.16.0.181:44937 #23775 (774 connections now open)
Fri Jun 28 20:32:13 [initandlisten] connection accepted from 172.16.0.137:19675 #23776 (775 connections now open)
Fri Jun 28 20:32:14 [initandlisten] connection accepted from 172.16.0.4:28651 #23777 (776 connections now open)
Fri Jun 28 20:32:14 [initandlisten] connection accepted from 172.16.0.181:45455 #23778 (777 connections now open)
Fri Jun 28 20:32:14 [initandlisten] connection accepted from 172.16.0.181:45458 #23779 (778 connections now open)
Fri Jun 28 20:32:15 [initandlisten] connection accepted from 172.16.0.182:27549 #23780 (779 connections now open)
Fri Jun 28 20:32:15 [initandlisten] connection accepted from 172.16.0.181:45641 #23781 (780 connections now open)
Fri Jun 28 20:32:16 [initandlisten] connection accepted from 172.16.0.182:27841 #23782 (781 connections now open)
Fri Jun 28 20:32:16 [initandlisten] connection accepted from 127.0.0.1:54645 #23783 (782 connections now open)
Fri Jun 28 20:32:16 [initandlisten] connection accepted from 172.16.0.181:45788 #23784 (783 connections now open)
Fri Jun 28 20:32:17 [conn1491] end connection 172.16.0.242:51718 (782 connections now open)
Fri Jun 28 20:32:17 [initandlisten] connection accepted from 172.16.0.242:51725 #23785 (783 connections now open)
Fri Jun 28 20:32:19 [initandlisten] connection accepted from 172.16.0.32:15833 #23786 (784 connections now open)
Fri Jun 28 20:32:19 [initandlisten] connection accepted from 172.16.0.181:46297 #23787 (785 connections now open)

          • SERVER RESTARTED *****

Fri Jun 28 20:52:45 [initandlisten] MongoDB starting : pid=9517 port=27020 dbpath=/var/lib/mongo 64-bit host=zuemongo5.zulily.com
Fri Jun 28 20:52:45 [initandlisten] db version v2.2.1, pdfile version 4.5
Fri Jun 28 20:52:45 [initandlisten] git version: d6764bf8dfe0685521b8bc7b98fd1fab8cfeb5ae
Fri Jun 28 20:52:45 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
Fri Jun 28 20:52:45 [initandlisten] options:

{ config: "/etc/mongod.conf", dbpath: "/var/lib/mongo", fork: "true", logappend: "true", logpath: "/var/log/mongo/mongod.log", oplogSize: 5000, port: 27020, replSet: "zumongous", rest: "true" }

Fri Jun 28 20:52:45 [initandlisten] journal dir=/var/lib/mongo/journal
Fri Jun 28 20:52:45 [initandlisten] recover begin
Fri Jun 28 20:52:45 [initandlisten] recover lsn: 1006869
Fri Jun 28 20:52:45 [initandlisten] recover /var/lib/mongo/journal/j._3
Fri Jun 28 20:52:45 [initandlisten] recover skipping application of section seq:408618 < lsn:1006869
Fri Jun 28 20:52:46 [initandlisten] recover skipping application of section seq:468234 < lsn:1006869
Fri Jun 28 20:52:46 [initandlisten] recover skipping application of section seq:587600 < lsn:1006869
Fri Jun 28 20:52:46 [initandlisten] recover /var/lib/mongo/journal/j._4
Fri Jun 28 20:52:46 [initandlisten] recover skipping application of section seq:647542 < lsn:1006869
Fri Jun 28 20:52:46 [initandlisten] recover skipping application of section seq:707486 < lsn:1006869
Fri Jun 28 20:52:46 [initandlisten] recover skipping application of section seq:767346 < lsn:1006869
Fri Jun 28 20:52:46 [initandlisten] recover skipping application of section seq:827234 < lsn:1006869
Fri Jun 28 20:52:46 [initandlisten] recover skipping application of section seq:887019 < lsn:1006869
[root@zuemongo5 mongo]#

Comment by Tom Laramee [ 30/Jun/13 ]

This is zuemongo2 ... it's currently running 2.2.5 and i think it should be running 2.2.1. Note that there are two restarts in the log .. I only initiated one of them (I suspect the latter).

Restart #1: 2.2.5
Restart #2: 2.2.1

Question: Why is the final version info 2.2.5? The active daemon is 2.2.1. I'm pretty sure that the active daemon is 2.2.1 and that the reporting of the version # is wrong.

[root@zuemongo2 mongo]# grep -A 20 "SERVER RESTARTED" 29

          • SERVER RESTARTED *****

Fri Jun 28 20:49:03 [initandlisten] MongoDB starting : pid=3303 port=27019 dbpath=/var/lib/mongo 64-bit host=zuemongo2.pubip.peer1.net
Fri Jun 28 20:49:03 [initandlisten] db version v2.2.5, pdfile version 4.5
Fri Jun 28 20:49:03 [initandlisten] git version: 14d8c4d1eb320ab10c6956f6e4b52263249bc0b4
Fri Jun 28 20:49:03 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
Fri Jun 28 20:49:03 [initandlisten] options:

{ config: "/etc/mongod.conf", dbpath: "/var/lib/mongo", fork: "true", logappend: "true", logpath: "/var/log/mongo/mongod.log", oplogSize: 5000, port: 27019, replSet: "zumongous", rest: "true" }

Fri Jun 28 20:49:03 [initandlisten] journal dir=/var/lib/mongo/journal
Fri Jun 28 20:49:03 [initandlisten] recover : no journal files present, no recovery needed
Fri Jun 28 20:49:04 [initandlisten] preallocateIsFaster=true 10.64
Fri Jun 28 20:49:05 [initandlisten] preallocateIsFaster=true 9.54
Fri Jun 28 20:49:06 [initandlisten] preallocateIsFaster=true 11.2
Fri Jun 28 20:49:06 [initandlisten] preallocateIsFaster check took 3.757 secs
Fri Jun 28 20:49:06 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.0
Fri Jun 28 20:49:16 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.1
Fri Jun 28 20:49:26 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.2
Fri Jun 28 20:49:36 [initandlisten] waiting for connections on port 27019
Fri Jun 28 20:49:36 [websvr] admin web console waiting for connections on port 28019
Fri Jun 28 20:49:36 [initandlisten] connection accepted from 172.16.0.137:49116 #1 (1 connection now open)
Fri Jun 28 20:49:36 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)

          • SERVER RESTARTED *****

Fri Jun 28 20:49:49 [initandlisten] MongoDB starting : pid=17229 port=27019 dbpath=/var/lib/mongo 64-bit host=zuemongo2.pubip.peer1.net
Fri Jun 28 20:49:49 [initandlisten] db version v2.2.1, pdfile version 4.5
Fri Jun 28 20:49:49 [initandlisten] git version: d6764bf8dfe0685521b8bc7b98fd1fab8cfeb5ae
Fri Jun 28 20:49:49 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
Fri Jun 28 20:49:49 [initandlisten] options:

{ config: "/etc/mongod.conf", dbpath: "/var/lib/mongo", fork: "true", logappend: "true", logpath: "/var/log/mongo/mongod.log", oplogSize: 5000, port: 27019, replSet: "zumongous", rest: "true" }

Fri Jun 28 20:49:49 [initandlisten] connection accepted from 172.16.0.137:58435 #13596 (208 connections now open)
Fri Jun 28 20:49:49 [initandlisten] exception in initAndListen: 10310 Unable to lock file: /var/lib/mongo/mongod.lock. Is a mongod instance already running?, terminating
Fri Jun 28 20:49:49 dbexit:
Fri Jun 28 20:49:49 [initandlisten] shutdown: going to close listening sockets...
Fri Jun 28 20:49:49 [initandlisten] shutdown: going to flush diaglog...
Fri Jun 28 20:49:49 [initandlisten] shutdown: going to close sockets...
Fri Jun 28 20:49:49 [initandlisten] shutdown: waiting for fs preallocator...
Fri Jun 28 20:49:49 [initandlisten] shutdown: lock for final commit...
Fri Jun 28 20:49:49 [initandlisten] shutdown: final commit...
Fri Jun 28 20:49:49 [initandlisten] shutdown: closing all files...
Fri Jun 28 20:49:49 [initandlisten] closeAllFiles() finished
Fri Jun 28 20:49:49 dbexit: really exiting now
Fri Jun 28 20:49:49 [initandlisten] connection accepted from 172.16.0.137:58438 #13597 (209 connections now open)

Comment by Tom Laramee [ 30/Jun/13 ]

The maintenance I did was on 6/28 at approx 8pm pacific time:

This is zuemongo1 .. which is v2.2.1, which is what I expect:

[root@zuemongo1 mongo]# grep -A 20 "SERVER RESTARTED" 29

          • SERVER RESTARTED *****

Fri Jun 28 21:22:58 [initandlisten] MongoDB starting : pid=12341 port=27017 dbpath=/var/lib/mongo 64-bit host=zuemongo1.pubip.peer1.net
Fri Jun 28 21:22:58 [initandlisten]
Fri Jun 28 21:22:58 [initandlisten] ** WARNING: /proc/sys/vm/zone_reclaim_mode is 1
Fri Jun 28 21:22:58 [initandlisten] ** We suggest setting it to 0
Fri Jun 28 21:22:58 [initandlisten] ** http://www.kernel.org/doc/Documentation/sysctl/vm.txt
Fri Jun 28 21:22:58 [initandlisten] db version v2.2.1, pdfile version 4.5
Fri Jun 28 21:22:58 [initandlisten] git version: d6764bf8dfe0685521b8bc7b98fd1fab8cfeb5ae
Fri Jun 28 21:22:58 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
Fri Jun 28 21:22:58 [initandlisten] options:

{ config: "/etc/mongod.conf", dbpath: "/var/lib/mongo", fork: "true", logappend: "true", logpath: "/var/log/mongo/mongod.log", oplogSize: 5000, replSet: "zumongous", rest: "true" }

Fri Jun 28 21:22:58 [initandlisten] journal dir=/var/lib/mongo/journal
Fri Jun 28 21:22:58 [initandlisten] recover : no journal files present, no recovery needed
Fri Jun 28 21:22:59 [initandlisten] preallocateIsFaster=true 8.42
Fri Jun 28 21:22:59 [initandlisten] preallocateIsFaster=true 8.2
Fri Jun 28 21:23:01 [initandlisten] preallocateIsFaster=true 7.6
Fri Jun 28 21:23:01 [initandlisten] preallocateIsFaster check took 3.107 secs
Fri Jun 28 21:23:01 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.0
Fri Jun 28 21:23:12 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.1
Fri Jun 28 21:23:21 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.2

Comment by Tom Laramee [ 30/Jun/13 ]

Please re-open this ticket.

Comment by Tom Laramee [ 30/Jun/13 ]

I take it all back ... the plot thickens / this is unresolved.

Please re-open this ticket.

Here are the "SERVER RESTARTS" from the logs for all 5 servers in this replica set.

Before I continue, I think I found a bug in the server – you'll see this on mongo5 in the log. It took several restarts to get this server to connect back to the replica set... it had a very odd error in the logs - it couldn't determine who the PRI was, not the SEC, and so it got stuck - all i saw in the logs was an error every ~10 seconds telling me that it couldn't connect to the replica set... so i ended up doing a "kill -kill" on it and restarting.

There were ~3 daemons spawned at that point - the only one i explicitly spawned was via a single "/etc/init.d/mongod start" ... the addt'l daemons came via mongod itself (meaning I did not start them).

In the next comment, I will post the server logs indicting that I explicitly started the daemons w/ v 2.2.1 for all servers - and that this is the last server restart for all servers.

Comment by Tom Laramee [ 30/Jun/13 ]

PS: feel free to close this ticket - thanks everyone for your assistance.

Comment by Tom Laramee [ 30/Jun/13 ]

hi Eliot:

great idea. the log shows that this is my error. this is zuemongo2, which is reporting
that it's running 2.2.5. here's the 1st ~20 lines of the log following the daemon bounce.
i'm not sure where i went wrong, but it's clear that i need to get mongo1 & 5 upgraded
to 2.2.5 ASAP.

--tom

          • SERVER RESTARTED *****

Fri Jun 28 20:49:03 [initandlisten] MongoDB starting : pid=3303 port=27019 dbpath=/var/lib/mongo 64-bit host=zuemongo2.pubip.peer1.net
Fri Jun 28 20:49:03 [initandlisten] db version v2.2.5, pdfile version 4.5
Fri Jun 28 20:49:03 [initandlisten] git version: 14d8c4d1eb320ab10c6956f6e4b52263249bc0b4
Fri Jun 28 20:49:03 [initandlisten] build info: Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49
Fri Jun 28 20:49:03 [initandlisten] options:

{ config: "/etc/mongod.conf", dbpath: "/var/lib/mongo", fork: "true", logappend: "true", logpath: "/var/log/mongo/mongod.log", oplogSize: 5000, port: 27019, replSet: "zumongous", rest: "true" }

Fri Jun 28 20:49:03 [initandlisten] journal dir=/var/lib/mongo/journal
Fri Jun 28 20:49:03 [initandlisten] recover : no journal files present, no recovery needed
Fri Jun 28 20:49:04 [initandlisten] preallocateIsFaster=true 10.64
Fri Jun 28 20:49:05 [initandlisten] preallocateIsFaster=true 9.54
Fri Jun 28 20:49:06 [initandlisten] preallocateIsFaster=true 11.2
Fri Jun 28 20:49:06 [initandlisten] preallocateIsFaster check took 3.757 secs
Fri Jun 28 20:49:06 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.0
Fri Jun 28 20:49:16 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.1
Fri Jun 28 20:49:26 [initandlisten] preallocating a journal file /var/lib/mongo/journal/prealloc.2
Fri Jun 28 20:49:36 [initandlisten] waiting for connections on port 27019
Fri Jun 28 20:49:36 [websvr] admin web console waiting for connections on port 28019
Fri Jun 28 20:49:36 [initandlisten] connection accepted from 172.16.0.137:49116 #1 (1 connection now open)
Fri Jun 28 20:49:36 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)
Fri Jun 28 20:49:36 [rsStart] replSet info you may need to run replSetInitiate – rs.initiate() in the shell – if that is not already done
Fri Jun 28 20:49:36 [conn1] end connection 172.16.0.137:49116 (0 connections now open)
Fri Jun 28 20:49:36 [initandlisten] connection accepted from 172.16.0.137:49117 #2 (1 connection now open)
Fri Jun 28 20:49:36 [conn2] end connection 172.16.0.137:49117 (0 connections now open)
Fri Jun 28 20:49:36 [initandlisten] connection accepted from 172.16.0.137:49121 #3 (1 connection now open)
Fri Jun 28 20:49:36 [conn3] end connection 172.16.0.137:49121 (0 connections now open)
Fri Jun 28 20:49:36 [initandlisten] connection accepted from 172.16.0.137:49129 #4 (1 connection now open)

Comment by Eliot Horowitz (Inactive) [ 30/Jun/13 ]

It can't report itself wrong, its built into the binary itself.
So however that binary was started, it was with 2.2.5.
I would look at:

  • ps
  • /proc/<mongo pid>/exe
    For some hints.
Comment by Tom Laramee [ 29/Jun/13 ]

Looking at just mongo2, which indicates it's running 2.2.5 via the buildInfo command:

$ cd /usr/bin

$ ls -la mongod*
lrwxrwxrwx 1 root root 12 Jun 28 20:49 mongod -> mongod.2.2.1
-rwxr-xr-x 1 root root 9322480 Apr 11 2012 mongod.2.0.2
-rwxr-xr-x 1 root root 11348288 Oct 30 2012 mongod.2.2.1
-rwxr-xr-x 1 root root 11454224 Jun 28 11:54 mongod.2.2.5

$ ./mongod --version
db version v2.2.1, pdfile version 4.5
Sat Jun 29 13:26:32 git version: d6764bf8dfe0685521b8bc7b98fd1fab8cfeb5ae

My question is: how is it possible for this server to be reporting that it's running 2.2.5 when the binary is clearly 2.2.1? At no point when mongod was running was the 2.2.5 binary the one that was sym linked.

Also note that the mongo shell for each server is 2.2.1, which is what i'd expect.

Note that the mongod.2.2.1 binary is a different size than the mongo2.2.5 binary - so they are different.

$ ./mongod.2.2.1 --version
db version v2.2.1, pdfile version 4.5
Sat Jun 29 13:29:16 git version: d6764bf8dfe0685521b8bc7b98fd1fab8cfeb5ae

$ ./mongod.2.2.5 --version
db version v2.2.5, pdfile version 4.5
Sat Jun 29 13:29:19 git version: 14d8c4d1eb320ab10c6956f6e4b52263249bc0b4

$ ls -la mongo*
lrwxrwxrwx 1 root root 11 Jun 28 20:49 mongo -> mongo.2.2.1
-rwxr-xr-x 1 root root 3077272 Apr 11 2012 mongo.2.0.2
-rwxr-xr-x 1 root root 4712840 Oct 30 2012 mongo.2.2.1
-rwxr-xr-x 1 root root 4730616 Jun 28 11:54 mongo.2.2.5

Comment by Tom Laramee [ 29/Jun/13 ]

Here is the buildinfo for each server ... my question will follow in the next comment:

[t@zuemongo1 ~]$ mongo
MongoDB shell version: 2.2.1
connecting to: test
zumongous:PRIMARY> db.serverBuildInfo()
{
"version" : "2.2.1",
"gitVersion" : "d6764bf8dfe0685521b8bc7b98fd1fab8cfeb5ae",
"sysInfo" : "Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49",
"versionArray" : [
2,
2,
1,
0
],
"bits" : 64,
"debug" : false,
"maxBsonObjectSize" : 16777216,
"ok" : 1
}

[t@zuemongo2 ~]$ mongo
MongoDB shell version: 2.2.1
connecting to: 127.0.0.1:27019/test
zumongous:SECONDARY> db.serverBuildInfo()
{
"version" : "2.2.5",
"gitVersion" : "14d8c4d1eb320ab10c6956f6e4b52263249bc0b4",
"sysInfo" : "Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49",
"versionArray" : [
2,
2,
5,
0
],
"bits" : 64,
"debug" : false,
"maxBsonObjectSize" : 16777216,
"ok" : 1
}

[t@zuemongo5 ~]$ mongo 127.0.0.1:27020
MongoDB shell version: 2.2.1
connecting to: 127.0.0.1:27020/test
zumongous:SECONDARY> db.serverBuildInfo()
{
"version" : "2.2.1",
"gitVersion" : "d6764bf8dfe0685521b8bc7b98fd1fab8cfeb5ae",
"sysInfo" : "Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49",
"versionArray" : [
2,
2,
1,
0
],
"bits" : 64,
"debug" : false,
"maxBsonObjectSize" : 16777216,
"ok" : 1
}

[t@zuemongo6 ~]$ mongo 127.0.0.1:27021
MongoDB shell version: 2.2.1
connecting to: 127.0.0.1:27021/test
zumongous:SECONDARY> db.serverBuildInfo()
{
"version" : "2.2.5",
"gitVersion" : "14d8c4d1eb320ab10c6956f6e4b52263249bc0b4",
"sysInfo" : "Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49",
"versionArray" : [
2,
2,
5,
0
],
"bits" : 64,
"debug" : false,
"maxBsonObjectSize" : 16777216,
"ok" : 1
}

[t@zuemongo7 ~]$ mongo 127.0.0.1:27022
MongoDB shell version: 2.2.1
connecting to: 127.0.0.1:27022/test
zumongous:SECONDARY> db.serverBuildInfo()
{
"version" : "2.2.5",
"gitVersion" : "14d8c4d1eb320ab10c6956f6e4b52263249bc0b4",
"sysInfo" : "Linux ip-10-2-29-40 2.6.21.7-2.ec2.v1.2.fc8xen #1 SMP Fri Nov 20 17:48:28 EST 2009 x86_64 BOOST_LIB_VERSION=1_49",
"versionArray" : [
2,
2,
5,
0
],
"bits" : 64,
"debug" : false,
"maxBsonObjectSize" : 16777216,
"ok" : 1
}

Comment by Daniel Pasette (Inactive) [ 29/Jun/13 ]

The mms agent gets the build info by running the "buildinfo" command on the host. You can login to the host in question and run:

db.serverBuildInfo()

You should see the same information there as you do in the "Last Ping" tab in the MMS host details.

Generated at Thu Feb 08 03:22:10 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.