2014년 11월 29일 토요일

A dummy getting Wired Tiger and MongoDB 2.8.0rc0 to work on a test system

This is written to help others who are as useless at MongoDB administration as I am. 

My goal was to get my test setup, a Debian VM in a Virtualbox on Windows 7 to run MongoDB 2.8.0rc0 with the new WiredTiger storage engine with Snappy compression. Mongo should also start, as soon as I fire up the VM. This post will explain some of the steps I took and where I had some issues. There is no guarantee anything here is correct, other than I got it to work doing the steps below.

Ok. Here goes.

So, first thing that I had to do was upgrade from 2.6.5 to 2.8.0. I followed the usual procedure to upgrade a standalone Mongo instance. No problems. Restarted my VM and started the mongo shell and entered "version()". The shell spit out "2.8.0-rc0". Great! Upgrade complete!

Now the hard part. According to the release notes, all you need to do to start up Mongo with the WiredTiger storage engine is to run the command:

mongod --storageEngine wiredtiger
I first killed the running mongod process and then tried this command. Errors. Hmmm...did some experimenting.
mongod --storageEngine wiredtiger --dbpath "/path/to/mongodb/data"
is what I needed for it to work. It seems you must also add the path to your data files to get it to work It also seems you must leave the console open, to then continue to use Mongo in this way, which isn't really too good. My goal was to fire up the database with this configuration at startup of the VM. 

So what to do? 

I started to google some more and don't ask me how I got to it, but I found some YAML configuration files for using WiredTiger from a cool chap named Adam Comerford.

He has entered some different configurations examples for different ways to use WiredTiger in his Github. I took the one I wanted with the Snappy compression, which is actually the default.

storage: dbPath: "/ssd/db/wt_snappy" engine: "wiredtiger" systemLog: destination: file path: "/data/wt_snappy/mongodb.log" processManagement: fork: true

But, hmm...how to use these config parameters? I added them in my mongodb.conf file under /etc changing out my own system's parameters, but no go. Mongo didn't start. 

Hmm...did some more googling (yes, I am such a noob) and read up on the config file and how it was changed to YAML for version 2.6.0 and that the old format is still the default, which is what I was using. The documentation doesn't really explain what to do to convert the default format for the config file to YAML. I did a bit more (re)searching and low and behold, I ran into this Jira with a great comment from Adam! It basically shows what the default YAML config could look like and then it went click in my head! I replaced my config file with Adams adding the other entries for WiredTiger. 

Restarted my VM. Damn. Still doesn't work. "Oh boy", I thought. Now what? Then I remembered, something that is so often asked for and what Asya just taught to me 3 days ago about issues and finding the cause for the issue. The thing to do is.......go to the error log! So I did and what did I find? 

2014-11-16T11:16:07.148+0000 E STORAGE  [initandlisten] WiredTiger (13) [1416136567:148416][1916:0x7ff215b3ab60], wiredtiger_open: /var/lib/mongodb/WiredTiger.lock: Permission denied
2014-11-16T11:16:07.148+0000 I -        [initandlisten] Fatal assertion 28519 UnknownError 13: Permission denied

And I remembered, Mongo was telling me earlier, I was starting Mongod as root, which isn't a good idea. I went to the /var/lib/mongodb/ path mentioned in the error and found the files were owned by "root". Haha! I am not that much of a noob. I changed the owner to monogdb for all the files in the directory. I fired up my VM again and yippeee! Mongo is working with 2.8.0-rc0 and WiredTiger. 



Thanks for the write up and pointing out Adam's helpful config examples. These actually come from a blog write up he did when experimenting with WiredTiger:http://comerford.cc/wordpress/2014/11/12/mongodb-2-8-new-wiredtiger-storage-engine-adds-compression/.

One thing to note: mongod does not look for a configuration file by default so if you're starting mongod via command-line to test you would have to provide the path via --config, eg:

mongod --config /etc/mongod.conf

Starting up via the command line can be useful for testing different versions, but in a normal environment you would use a packaged install (eg: Install MongoDB on Debian) which includes a service definition. In this case after making your config changes you would do:

sudo service mongod restart


Exactly. Good points. The packaged install for Debian is what I've had from the beginning. I guess that is an important piece of information to know. With the packaged installation, there is also an elaborate startup script from Javier Fernandez-Sanguino installed under /etc/init.d/mongodb, which includes the --config /etc/mongodb.conf setting for the daemon to start with. It is responsible for Mongo starting at boot time of the VM. I didn't add it to my story above, because it didn't work, but I actually tried to change this script to add the WiredTiger stuff first. Noob like.

What is strange though, even though I did the package install, the service command doesn't work. The only way I can use the script to stop, start or restart mongo is with 

sh /etc/init.d/mongodb start|stop|restart



I've somehow zapped my test system. I wanted to change back to Mmap and now when I start Mongo, I can access the database over the shell with "mongo", but the service isn't working as a service and my application can't access Mongo over the port 27017. The error log doesn't show any hint (to me) about what is going wrong. Is there another place to look, where I might see what is not working right? Here is the mongo error log anyway. Maybe you can see something.

2014-11-24T08:25:30.100+0000 I CONTROL  ***** SERVER RESTARTED *****
2014-11-24T08:25:30.104+0000 D SHARDING isInRangeTest passed
2014-11-24T08:25:30.105+0000 I CONTROL  [initandlisten] MongoDB starting : pid=3652 port=27017 dbpath=/var/lib/mongodb 64-bit host=packer-virtualbox
2014-11-24T08:25:30.105+0000 I CONTROL  [initandlisten] db version v2.8.0-rc0
2014-11-24T08:25:30.105+0000 I CONTROL  [initandlisten] git version: b6c4e2491c1442b05a160acda0d78001f56a2ade
2014-11-24T08:25:30.105+0000 I CONTROL  [initandlisten] build info: Linuxbuild4.nj1.10gen.cc 2.6.32-431.3.1.el6.x86_64 #1 SMP Fri Jan 3 21:39:27 UTC 2014 x86_64 BOOST_LIB_VERSION=1_49
2014-11-24T08:25:30.105+0000 I CONTROL  [initandlisten] allocator: tcmalloc
2014-11-24T08:25:30.105+0000 I CONTROL  [initandlisten] options: { config: "/etc/mongodb.conf", processManagement: { fork: true }, storage: { dbPath: "/var/lib/mongodb", engine: "mmapv1" }, systemLog: { destination: "file", logAppend: true, path: "/var/log/mongodb/mongodb.log", verbosity: 5 } }
2014-11-24T08:25:30.105+0000 D NETWORK  [initandlisten] fd limit hard:4096 soft:1024 max conn: 819
2014-11-24T08:25:30.107+0000 D STORAGE  [initandlisten] flushing directory /var/lib/mongodb
2014-11-24T08:25:30.110+0000 I JOURNAL  [initandlisten] journal dir=/var/lib/mongodb/journal
2014-11-24T08:25:30.110+0000 I JOURNAL  [initandlisten] recover : no journal files present, no recovery needed
2014-11-24T08:25:30.110+0000 D STORAGE  [initandlisten] flushing directory /var/lib/mongodb/journal
2014-11-24T08:25:30.110+0000 D COMMANDS [DataFileSync] BackgroundJob starting: DataFileSync
2014-11-24T08:25:30.112+0000 D STORAGE  [initandlisten] flushing directory /var/lib/mongodb/journal
2014-11-24T08:25:30.113+0000 D STORAGE  [initandlisten] enter repairDatabases (to check pdfile version #)
2014-11-24T08:25:30.113+0000 D STORAGE  [initandlisten]     Recovering database: test2
2014-11-24T08:25:30.119+0000 D STORAGE  [initandlisten] mmf open /var/lib/mongodb/test2.0
2014-11-24T08:25:30.119+0000 D STORAGE  [initandlisten] mmf finishOpening 0x7fb9ce290000 /var/lib/mongodb/test2.0 len:67108864
2014-11-24T08:25:30.119+0000 D STORAGE  [initandlisten] mmf open /var/lib/mongodb/test2.ns
2014-11-24T08:25:30.119+0000 D STORAGE  [initandlisten] mmf finishOpening 0x7fb9c9290000 /var/lib/mongodb/test2.ns len:16777216
2014-11-24T08:25:30.122+0000 D STORAGE  [initandlisten]     Recovering database: test3
2014-11-24T08:25:30.128+0000 D STORAGE  [initandlisten] mmf open /var/lib/mongodb/test3.0
2014-11-24T08:25:30.128+0000 D STORAGE  [initandlisten] mmf finishOpening 0x7fb9c4290000 /var/lib/mongodb/test3.0 len:67108864
2014-11-24T08:25:30.128+0000 D STORAGE  [initandlisten] mmf open /var/lib/mongodb/test3.ns
2014-11-24T08:25:30.128+0000 D STORAGE  [initandlisten] mmf finishOpening 0x7fb9bf290000 /var/lib/mongodb/test3.ns len:16777216
2014-11-24T08:25:30.131+0000 D STORAGE  [initandlisten]     Recovering database: test4
2014-11-24T08:25:30.136+0000 D STORAGE  [initandlisten] mmf open /var/lib/mongodb/test4.0
2014-11-24T08:25:30.136+0000 D STORAGE  [initandlisten] mmf finishOpening 0x7fb9ba290000 /var/lib/mongodb/test4.0 len:67108864
2014-11-24T08:25:30.136+0000 D STORAGE  [initandlisten] mmf open /var/lib/mongodb/test4.ns
2014-11-24T08:25:30.136+0000 D STORAGE  [initandlisten] mmf finishOpening 0x7fb9b5290000 /var/lib/mongodb/test4.ns len:16777216
2014-11-24T08:25:30.139+0000 D STORAGE  [initandlisten]     Recovering database: test_database
2014-11-24T08:25:30.144+0000 D STORAGE  [initandlisten] mmf open /var/lib/mongodb/test_database.0
2014-11-24T08:25:30.144+0000 D STORAGE  [initandlisten] mmf finishOpening 0x7fb9b0290000 /var/lib/mongodb/test_database.0 len:67108864
2014-11-24T08:25:30.144+0000 D STORAGE  [initandlisten] mmf open /var/lib/mongodb/test_database.ns
2014-11-24T08:25:30.144+0000 D STORAGE  [initandlisten] mmf finishOpening 0x7fb9ab290000 /var/lib/mongodb/test_database.ns len:16777216
2014-11-24T08:25:30.147+0000 D STORAGE  [initandlisten]     Recovering database: local
2014-11-24T08:25:30.152+0000 D STORAGE  [initandlisten] mmf open /var/lib/mongodb/local.0
2014-11-24T08:25:30.152+0000 D STORAGE  [initandlisten] mmf finishOpening 0x7fb9a6290000 /var/lib/mongodb/local.0 len:67108864
2014-11-24T08:25:30.152+0000 D STORAGE  [initandlisten] mmf open /var/lib/mongodb/local.ns
2014-11-24T08:25:30.152+0000 D STORAGE  [initandlisten] mmf finishOpening 0x7fb9a1290000 /var/lib/mongodb/local.ns len:16777216
2014-11-24T08:25:30.155+0000 D STORAGE  [initandlisten] done repairDatabases
2014-11-24T08:25:30.155+0000 D QUERY    [initandlisten] [QLOG] Running query:
ns=admin.system.roles limit=0 skip=0
Tree: $and
Sort: {}
Proj: {}
2014-11-24T08:25:30.155+0000 D QUERY    [initandlisten] Running query: query: {} sort: {} projection: {} skip: 0 limit: 0
2014-11-24T08:25:30.155+0000 D QUERY    [initandlisten] Collection admin.system.roles does not exist. Using EOF plan: query: {} sort: {} projection: {} skip: 0 limit: 0
2014-11-24T08:25:30.155+0000 D QUERY    [initandlisten] [QLOG] Not caching executor but returning 0 results.
2014-11-24T08:25:30.155+0000 I QUERY    [initandlisten] query admin.system.roles planSummary: EOF ntoreturn:0 ntoskip:0 nscanned:0 nscannedObjects:0 keyUpdates:0 numYields:0  nreturned:0 reslen:20 0ms
2014-11-24T08:25:30.157+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test2.users
2014-11-24T08:25:30.158+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test2.system.indexes
2014-11-24T08:25:30.158+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test2.system.namespaces
2014-11-24T08:25:30.158+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test2.albums
2014-11-24T08:25:30.158+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test3.albums
2014-11-24T08:25:30.158+0000 D COMMANDS [TTLMonitor] BackgroundJob starting: TTLMonitor
2014-11-24T08:25:30.158+0000 D COMMANDS [PeriodicTaskRunner] BackgroundJob starting: PeriodicTaskRunner
2014-11-24T08:25:30.158+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test3.system.namespaces
2014-11-24T08:25:30.158+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test3.system.indexes
2014-11-24T08:25:30.158+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test3.users
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test4.albums2
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test4.albums3
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test4.albums4
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test4.system.namespaces
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test4.users
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test4.albums
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test4.system.indexes
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test_database.User
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test_database.system.indexes
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: test_database.system.namespaces
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: local.startup_log
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: local.system.indexes
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] IndexRebuilder::checkNS: local.system.namespaces
2014-11-24T08:25:30.159+0000 D INDEXING [initandlisten] checking complete
2014-11-24T08:25:30.159+0000 D COMMANDS [initandlisten] run command local.$cmd { create: "startup_log", size: 10485760, capped: true }
2014-11-24T08:25:30.159+0000 D STORAGE  [initandlisten] create collection local.startup_log { size: 10485760, capped: true }
2014-11-24T08:25:30.159+0000 I QUERY    [initandlisten] command local.$cmd command: create { create: "startup_log", size: 10485760, capped: true } ntoreturn:1 keyUpdates:0 numYields:0  reslen:85 0ms
2014-11-24T08:25:30.159+0000 I WRITES   [initandlisten] insert local.startup_log ninserted:1 keyUpdates:0 numYields:0  0ms
2014-11-24T08:25:30.159+0000 I NETWORK  [initandlisten] waiting for connections on port 27017
2014-11-24T08:25:30.159+0000 D COMMANDS [ClientCursorMonitor] BackgroundJob starting: ClientCursorMonitor
2014-11-24T08:25:30.225+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:30.225+0000 D JOURNAL  [journal] journal WRITETODATAFILES 1
2014-11-24T08:25:30.225+0000 D JOURNAL  [journal] journal WRITETODATAFILES 2
2014-11-24T08:25:30.225+0000 D JOURNAL  [journal] journal WRITETODATAFILES 0.064ms
2014-11-24T08:25:30.225+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:30.225+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:30.226+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 0 n:10 0ms
2014-11-24T08:25:30.226+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:30.328+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:30.328+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:30.328+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:30.328+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 0 n:1 0ms
2014-11-24T08:25:30.328+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:30.431+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:30.431+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:30.431+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:30.431+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 1 n:1 0ms
2014-11-24T08:25:30.431+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:30.534+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:30.534+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:30.534+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:30.534+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 2 n:1 0ms
2014-11-24T08:25:30.534+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:30.638+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:30.638+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:30.638+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:30.638+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 3 n:1 0ms
2014-11-24T08:25:30.638+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:30.742+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:30.742+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:30.742+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:30.742+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 4 n:1 0ms
2014-11-24T08:25:30.742+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:30.845+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:30.845+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:30.845+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:30.845+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 5 n:1 0ms
2014-11-24T08:25:30.845+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:30.947+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:30.947+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:30.947+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:30.947+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 6 n:1 0ms
2014-11-24T08:25:30.947+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:31.050+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:31.050+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:31.050+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:31.050+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 7 n:1 0ms
2014-11-24T08:25:31.050+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:31.152+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:31.153+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:31.153+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:31.153+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 8 n:1 0ms
2014-11-24T08:25:31.153+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:31.256+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:31.256+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:31.256+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:31.256+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 9 n:1 0ms
2014-11-24T08:25:31.256+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:31.359+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:31.359+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:31.359+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:31.359+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 0 n:1 0ms
2014-11-24T08:25:31.359+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:31.462+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:31.462+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:31.462+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:31.462+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 1 n:1 0ms
2014-11-24T08:25:31.462+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:31.566+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:31.566+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:31.566+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:31.566+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 2 n:1 0ms
2014-11-24T08:25:31.566+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:31.668+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:31.668+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:31.668+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:31.668+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 3 n:1 0ms
2014-11-24T08:25:31.668+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:31.771+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:31.771+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:31.771+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:31.771+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 4 n:1 0ms
2014-11-24T08:25:31.771+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:31.874+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:31.874+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:31.874+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:31.875+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 5 n:1 0ms
2014-11-24T08:25:31.875+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:31.980+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:31.980+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:31.980+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:31.980+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 6 n:1 0ms
2014-11-24T08:25:31.980+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:32.082+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:32.082+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:32.082+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:32.082+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 7 n:1 0ms
2014-11-24T08:25:32.082+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:32.185+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:32.185+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:32.185+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:32.185+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 8 n:1 0ms
2014-11-24T08:25:32.185+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:32.289+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:32.289+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:32.289+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:32.289+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 9 n:1 0ms
2014-11-24T08:25:32.289+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:32.392+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:32.392+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:32.392+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:32.392+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 0 n:1 0ms
2014-11-24T08:25:32.392+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:32.494+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:32.495+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:32.495+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:32.495+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 1 n:1 0ms
2014-11-24T08:25:32.495+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:32.597+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:32.597+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:32.597+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:32.597+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 2 n:1 0ms
2014-11-24T08:25:32.597+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:32.700+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:32.700+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:32.700+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:32.700+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 3 n:1 0ms
2014-11-24T08:25:32.700+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:32.803+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:32.803+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:32.803+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:32.803+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 4 n:1 0ms
2014-11-24T08:25:32.803+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:32.906+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:32.906+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:32.906+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:32.906+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 5 n:1 0ms
2014-11-24T08:25:32.906+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:33.008+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:33.009+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:33.009+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:33.009+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 6 n:1 0ms
2014-11-24T08:25:33.009+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:33.113+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:33.113+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:33.113+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:33.113+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 7 n:1 0ms
2014-11-24T08:25:33.113+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:33.216+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:33.216+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:33.216+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:33.216+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 8 n:1 0ms
2014-11-24T08:25:33.216+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:33.319+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:33.319+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:33.319+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:33.319+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 9 n:1 0ms
2014-11-24T08:25:33.319+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:33.421+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:33.421+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:33.422+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:33.422+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 0 n:1 0ms
2014-11-24T08:25:33.422+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:33.524+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:33.524+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:33.524+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:33.524+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 1 n:1 0ms
2014-11-24T08:25:33.524+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:33.627+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:33.628+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:33.628+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:33.628+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 2 n:1 0ms
2014-11-24T08:25:33.628+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:33.731+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:33.731+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:33.731+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:33.731+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 3 n:1 0ms
2014-11-24T08:25:33.731+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:33.834+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:33.834+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:33.834+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:33.834+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 4 n:1 0ms
2014-11-24T08:25:33.834+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:33.937+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:33.937+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:33.937+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:33.937+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 5 n:1 0ms
2014-11-24T08:25:33.937+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:34.040+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:34.040+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:34.040+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:34.040+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 6 n:1 0ms
2014-11-24T08:25:34.040+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:34.143+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:34.143+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:34.144+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:34.144+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 7 n:1 0ms
2014-11-24T08:25:34.144+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:34.246+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:34.246+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:34.246+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:34.246+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 8 n:1 0ms
2014-11-24T08:25:34.246+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:34.349+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:34.349+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:34.349+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:34.349+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 9 n:1 0ms
2014-11-24T08:25:34.349+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:34.454+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:34.454+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:34.454+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:34.454+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 0 n:1 0ms
2014-11-24T08:25:34.454+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:34.557+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:34.557+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:34.557+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:34.557+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 1 n:1 0ms
2014-11-24T08:25:34.557+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:34.660+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:34.660+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:34.660+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:34.660+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 2 n:1 0ms
2014-11-24T08:25:34.660+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:34.762+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:34.762+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:34.762+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:34.762+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 3 n:1 0ms
2014-11-24T08:25:34.762+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:34.867+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:34.867+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:34.867+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:34.867+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 4 n:1 0ms
2014-11-24T08:25:34.867+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:34.971+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:34.971+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:34.971+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:34.971+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 5 n:1 0ms
2014-11-24T08:25:34.971+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:35.074+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:35.074+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:35.074+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:35.074+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 6 n:1 0ms
2014-11-24T08:25:35.074+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:35.178+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:35.178+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:35.178+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:35.178+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 7 n:1 0ms
2014-11-24T08:25:35.178+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:35.282+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:35.282+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:35.282+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:35.282+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 8 n:1 0ms
2014-11-24T08:25:35.282+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:35.384+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:35.384+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:35.384+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:35.384+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 9 n:1 0ms
2014-11-24T08:25:35.384+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:35.486+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:35.486+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:35.486+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:35.486+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 0 n:1 0ms
2014-11-24T08:25:35.486+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:35.589+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:35.589+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:35.589+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:35.589+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 1 n:1 0ms
2014-11-24T08:25:35.589+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:35.692+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:35.692+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:35.692+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:35.692+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 2 n:1 0ms
2014-11-24T08:25:35.692+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:35.794+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:35.794+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:35.794+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:35.794+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 3 n:1 0ms
2014-11-24T08:25:35.794+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:35.897+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:35.897+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:35.897+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:35.897+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 4 n:1 0ms
2014-11-24T08:25:35.897+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:36.000+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:36.000+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:36.000+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:36.000+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 5 n:1 0ms
2014-11-24T08:25:36.000+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:36.102+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:36.102+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:36.102+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:36.102+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 6 n:1 0ms
2014-11-24T08:25:36.102+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:36.206+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:36.206+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:36.206+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:36.206+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 7 n:1 0ms
2014-11-24T08:25:36.206+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:36.309+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:36.309+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:36.309+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:36.309+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 8 n:1 0ms
2014-11-24T08:25:36.309+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:36.412+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:36.412+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:36.412+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:36.412+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 9 n:1 0ms
2014-11-24T08:25:36.412+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:36.514+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:36.514+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:36.514+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:36.514+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 0 n:1 0ms
2014-11-24T08:25:36.514+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:36.617+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:36.617+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:36.617+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:36.617+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 1 n:1 0ms
2014-11-24T08:25:36.617+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:36.721+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:36.721+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:36.721+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:36.721+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 2 n:1 0ms
2014-11-24T08:25:36.721+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:36.824+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:36.824+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:36.824+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:36.824+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 3 n:1 0ms
2014-11-24T08:25:36.824+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:36.928+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:36.928+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:36.928+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:36.928+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 4 n:1 0ms
2014-11-24T08:25:36.928+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:37.031+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:37.031+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:37.031+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:37.031+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 5 n:1 0ms
2014-11-24T08:25:37.031+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:37.134+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:37.134+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:37.134+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:37.134+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 6 n:1 0ms
2014-11-24T08:25:37.134+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:37.237+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:37.237+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:37.237+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:37.237+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 7 n:1 0ms
2014-11-24T08:25:37.237+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:37.340+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:37.340+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:37.340+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:37.340+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 8 n:1 0ms
2014-11-24T08:25:37.340+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:37.444+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:37.444+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:37.444+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:37.444+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 9 n:1 0ms
2014-11-24T08:25:37.444+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:37.546+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:37.546+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:37.546+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:37.546+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 0 n:1 0ms
2014-11-24T08:25:37.546+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:37.649+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:37.649+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:37.649+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:37.649+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 1 n:1 0ms
2014-11-24T08:25:37.649+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:37.752+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:37.752+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:37.752+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:37.752+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 2 n:1 0ms
2014-11-24T08:25:37.752+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:37.855+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:37.855+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:37.855+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:37.855+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 3 n:1 0ms
2014-11-24T08:25:37.855+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:37.959+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:37.959+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:37.959+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:37.960+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 4 n:1 0ms
2014-11-24T08:25:37.960+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:38.062+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:38.062+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:38.062+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:38.062+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 5 n:1 0ms
2014-11-24T08:25:38.062+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:38.165+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:38.165+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:38.165+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:38.165+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 6 n:1 0ms
2014-11-24T08:25:38.165+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:38.268+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:38.268+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:38.268+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:38.268+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 7 n:1 0ms
2014-11-24T08:25:38.268+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:38.372+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:38.372+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:38.372+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:38.372+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 8 n:1 0ms
2014-11-24T08:25:38.372+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:38.475+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:38.475+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:38.475+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:38.475+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 9 n:1 0ms
2014-11-24T08:25:38.475+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:38.577+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:38.577+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:38.577+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:38.577+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 0 n:1 0ms
2014-11-24T08:25:38.577+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:38.681+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:38.681+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:38.681+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:38.681+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 1 n:1 0ms
2014-11-24T08:25:38.681+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:38.783+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:38.783+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:38.783+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:38.783+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 2 n:1 0ms
2014-11-24T08:25:38.783+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:38.886+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:38.886+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:38.886+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:38.886+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 3 n:1 0ms
2014-11-24T08:25:38.886+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:38.990+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:38.990+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:38.990+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:38.990+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 4 n:1 0ms
2014-11-24T08:25:38.990+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:39.093+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:39.093+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:39.093+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:39.093+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 5 n:1 0ms
2014-11-24T08:25:39.093+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:39.197+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:39.197+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:39.197+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:39.197+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 6 n:1 0ms
2014-11-24T08:25:39.197+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:39.301+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:39.301+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:39.301+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:39.301+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 7 n:1 0ms
2014-11-24T08:25:39.301+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:39.404+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:39.404+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:39.404+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:39.404+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 8 n:1 0ms
2014-11-24T08:25:39.404+0000 D JOURNAL  [journal] remapPrivateView end
2014-11-24T08:25:39.507+0000 D JOURNAL  [journal] _groupCommit 
2014-11-24T08:25:39.507+0000 D JOURNAL  [journal] groupCommit end
2014-11-24T08:25:39.507+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW
2014-11-24T08:25:39.507+0000 D JOURNAL  [journal] journal REMAPPRIVATEVIEW done startedAt: 9 n:1 0ms
2014-11-24T08:25:39.507+0000 D JOURNAL  [journal] remapPrivateView end



Ok. I went googling quickly and found something about the .lock file and I deleted it. Now I can connect with my application on restarting Mongod, but the service is still showing up as failing. Hmm.....



s.molinari wrote:
I've somehow zapped my test system. I wanted to change back to Mmap and now when I start Mongo, I can access the database over the shell with "mongo", but the service isn't working as a service and my application can't access Mongo over the port 27017. The error log doesn't show any hint (to me) about what is going wrong. Is there another place to look, where I might see what is not working right? Here is the mongo error log anyway. Maybe you can see something.

Hi Scott,

You should be able to spot any obvious errors on startup with the default log level .. verbosity of 5 adds a lot of noise about internal state :).

Deleting the .lock file definitely isn't a recommended first step for troubleshooting startup. On Linux the lock file should either have a process ID (if a `mongod` is still running or shutdown was unclean) or be empty (on normal shutdown).

If the service fails to start but you can connect using the mongo shell, it sounds like you still have a running instance of mongod that hasn't been shutdown (check at a unix shell prompt with: `ps -ef | grep mongod`). 

Do the times in the log file correspond to your service startup? I don't see the server shutting down in the log so you might actually be looking at the log file for a running server instance rather than the mongod you are trying to start with a service.

I would login via the mongo shell and shut the running instance down with:

use admin
db
.shutdownServer()

You can then recheck there are no running mongod process with `ps -ef | grep mongod` , and should be able to start the service if there are no errors with the configuration.



Thanks for the quick answer. 

I had already increased the verbosity to 5 and I also added "traceAllExceptions: true". 

The strange thing is a mongo process is started, but it doesn't work completely correctly. 

Is it possible the service start can get a good mongod process running, but still fail the service start procedure? If so, what could cause the failure?

Now my noobness is shining, isn't it?



et's go back to storage engines:

You said you wanted to switch back - but you cannot use the same data directory for mmap and wiredTiger (files are different, formats are incompatible).   Is it possible that you are pointing at the wrong data directory?



I wish there was a way to erase certain content from the internet entirely.

My first order of business would be to remove every single recommendation to either delete the mongod.lock file or to run repair or both.

The cases where one or both of those two are necessary (in any recent versions) are close to non-existent.



Hmm...that is interesting and makes complete sense, but the fact the data directories aren't compatible isn't mentioned anywhere, like saying to switch, you need to reimport data or something like that. That is most likely my noob mistake too. I had switched to WT with the same data directory, but it wasn't working, so I wanted to go back to Mmap. Now that you say the data directories need to be totally different locations, I will start from the beginning again. 

Still, why is Mmap now working, but only when I kill the process and start mongod over the service again (despite it showing as failed?)

I hate being a noob....LOL!



s.molinari wrote:
Hmm...that is interesting and makes complete sense, but the fact the data directories aren't compatible isn't mentioned anywhere, like saying to switch, you need to reimport data or something like that. That is most likely my noob mistake too. I had switched to WT with the same data directory, but it wasn't working, so I wanted to go back to Mmap. Now that you say the data directories need to be totally different locations, I will start from the beginning again. 

Hi Scott,

Existing files in the data directory may not be the issue in 2.8.0rc0; based on your earlier description I think you had another mongod process running and removed the mongod.lock file.

There is definitely potential for confusion if you mix & match files for multiple storage engines in the same dbpath (for example, restarting with a new storage engine might make it look as if your data has "disappeared"). There's an open issue to warn if files for a different storage engine are found in the data path: https://jira.mongodb.org/browse/SERVER-15986

> the data directories aren't compatible isn't mentioned anywhere, like saying to switch, you need to reimport data or something like that

The draft release notes for 2.8 mention that WiredTiger has a different on-disk format and that you either have to mongodump/mongorestore to import data or run a replica set with different storage engines per mongod: http://docs.mongodb.org/manual/release-notes/2.8/#storage-engines-improved-concurrency-document-level-locking-with-compression.

The release notes could be more explicit, but the same is true of migrating from WiredTiger to mmapv1 (or other storage engines). Expect the on-disk format to be different (that's the point, after all) and for sane housekeeping use distinct data paths.
 
Still, why is Mmap now working, but only when I kill the process and start mongod over the service again (despite it showing as failed?)

To be clear on the steps you took, it sounds likely you:
 - edited the /etc/mongodb.conf to change from wiredtiger to mmapv1
 - manually removed the mongod.lock file
 - tried to start the mongod service (which failed)
 - successfully connected with the mongo shell
 - killed the running mongod service
 - successfully started the mongod service

If so, the error was in removing the lock file :)

Are you able to successfully restart the service now? If you can't restart (or stop/start) the service perhaps there may be something else amiss in your configuration.



Hmm...I have to say the old German adage, "If you can read, you will clearly have an advantage." Doesn't translate well in English, but it basically means, you are an idiot, when you don't read properly.

I don't know how I missed that with the mongo dump and restore.

I'll give it another run and report back. Thanks for the help!



This doesn't look normal to me. 

When I try to shut down the server over the mongo shell, I get this output.

2014-11-24T18:18:48.870+0000 I NETWORK  DBClientCursor::init call() failed
server should be down...
2014-11-24T18:18:48.873+0000 I NETWORK  trying reconnect to127.0.0.1:27017 (127.0.0.1) failed
2014-11-24T18:18:48.874+0000 I NETWORK  reconnect 127.0.0.1:27017(127.0.0.1) ok
2014-11-24T18:18:48.876+0000 I NETWORK  Socket recv() errno:104 Connection reset by peer 127.0.0.1:27017
2014-11-24T18:18:48.876+0000 I NETWORK  SocketException: remote:127.0.0.1:27017 error: 9001 socket exception [RECV_ERROR] server [127.0.0.1:27017]
2014-11-24T18:18:48.876+0000 I NETWORK  DBClientCursor::init call() failed



Ok, I got everything working again. :)

I reinstalled 2.6.5 from scratch and then changed out the 2.8.0 binaries to upgrade to 2.8.0 rc2.

Now the mongod service works as expected. WiredTiger works as expected.

Do I also understand the WiredTiger file scheme? WiredTiger doesn't have the preallocation of files MmapV1 uses? Meaning, if I have a database of 1 GB, the server isn't going to waste 3 GB of disk space per database with WiredTiger?



You are correct, WiredTiger data/file format is completely different and it doesn't do the same sort of preallocation that Mmapv1 does.  In addition, it compresses data by default so you will tend to have much smaller data directories.

I'm working on a blog post on WT (it'll be probably a few posts) and one of my examples mmapv1 has 4GB to wiredTiger's 1.5GB.   That's probably typical, though another database which has very poorly compressible data has 9GB vs 13GB (again wiredTiger with smaller directory).



What is attractive with WT is, if the read/write performance can be fairly comparable to Mmapv1 (hopefully the 10-15% difference you mentioned will get smaller at some point in the future), then we could give customers their own database from the start with WT and not have to share a database among several smaller customers, in order to avoid the preallocated files taking up too much space. Our initial plan was to move growing customers to their own database, when they broke a certain threshold. We won't need this at all with WT, it seems. And the fact WT compresses data will also be a cost factor for sure, for anyone with tons of data and databases (like we really want to have) :-).

댓글 없음:

댓글 쓰기