[SERVER-14544] can't apply newCollectionsUsePowerOf2Sizes=false, neither config entry nor mongo shell command nor mongod command seems to work Created: 13/Jul/14  Updated: 10/Dec/14  Resolved: 14/Jul/14

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

Type: Bug Priority: Major - P3
Reporter: Kay Agahd Assignee: Ramon Fernandez Marina
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Related
Operating System: ALL
Participants:

 Description   

We are using v2.6.1 and learned that powerOf2Sizes is now the default memory allocation strategy (see also https://jira.mongodb.org/browse/CS-13109 ). However, we prefer not to use it because it consumes always 20% more RAM than the conventional mem alloc strategy.
So, we added the folling line to our mongod.config, which is btw. badly documented, so perhaps we used the wrong syntax?

setParameter=newCollectionsUsePowerOf2Sizes=false

However I assume that's the right syntax since the mongod logs showed that the parameter was picked up successfully:

2014-07-11T17:48:22.712+0200 ***** SERVER RESTARTED *****
2014-07-11T17:48:22.727+0200 [initandlisten] MongoDB starting : pid=12808 port=27017 dbpath=/data/mongod/db 64-bit host=s488
2014-07-11T17:48:22.736+0200 [initandlisten] db version v2.6.1
2014-07-11T17:48:22.736+0200 [initandlisten] git version: 4b95b086d2374bdcfcdf2249272fb552c9c726e8
2014-07-11T17:48:22.736+0200 [initandlisten] build info: Linux build14.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-07-11T17:48:22.736+0200 [initandlisten] allocator: tcmalloc
2014-07-11T17:48:22.736+0200 [initandlisten] options: { config: "/etc/mongod_mongod.conf", net: { http: { RESTInterfaceEnabled: true, enabled: true }, port: 27017 }, processManagement: { pidFilePath: "/data/mongod/mongod.pid" }, replication: { replSet: "offerStoreDE5" }, security: { keyFile: "/data/keyfile.txt" }, setParameter: { newCollectionsUsePowerOf2Sizes: "false" }, storage: { dbPath: "/data/mongod/db", directoryPerDB: true, journal: { enabled: false } }, systemLog: { destination: "file", logAppend: true, path: "/data/mongod/log/mongod.log" } }
2014-07-11T17:48:22.763+0200 [FileAllocator] allocating new datafile /data/mongod/db/local/local.ns, filling with zeroes...
2014-07-11T17:48:22.763+0200 [FileAllocator] creating directory /data/mongod/db/local/_tmp
2014-07-11T17:48:22.766+0200 [FileAllocator] done allocating datafile /data/mongod/db/local/local.ns, size: 16MB,  took 0 secs
2014-07-11T17:48:22.768+0200 [FileAllocator] allocating new datafile /data/mongod/db/local/local.0, filling with zeroes...
2014-07-11T17:48:22.768+0200 [FileAllocator] done allocating datafile /data/mongod/db/local/local.0, size: 64MB,  took 0 secs
2014-07-11T17:48:22.770+0200 [initandlisten] build index on: local.startup_log properties: { v: 1, key: { _id: 1 }, name: "_id_", ns: "local.startup_log" }
2014-07-11T17:48:22.770+0200 [initandlisten]     added index to empty collection
2014-07-11T17:48:22.772+0200 [initandlisten] waiting for connections on port 27017
2014-07-11T17:48:22.772+0200 [websvr] admin web console waiting for connections on port 28017
2014-07-11T17:48:22.773+0200 [rsStart] replSet can't get local.system.replset config from self or any seed (EMPTYCONFIG)

Before restarting mongod, we completely emptied the db directory, to be sure that all data will be allocated using the old memory allocation strategy.

Two days later I wondered why RAM consumption was still very high and I discovered, that db.offer.stats().userFlags:1, which means that powerOf2Sizes is still used.
So I executed the following command which I found in the doc to switch back to the old memory allocation strategy:

offerStoreDE5:SECONDARY> db.getSiblingDB('admin').runCommand( { setParameter: 1, newCollectionsUsePowerOf2Sizes: false } )
{ "was" : false, "ok" : 1 }
offerStoreDE5:SECONDARY>
offerStoreDE5:SECONDARY> use offerStore
switched to db offerStore
offerStoreDE5:SECONDARY> db.offer.stats()
{
        "ns" : "offerStore.offer",
        "count" : 55905283,
        "size" : 146846463152,
        "avgObjSize" : 2626,
        "storageSize" : 150970108880,
        "numExtents" : 91,
        "nindexes" : 10,
        "lastExtentSize" : 2146426864,
        "paddingFactor" : 1.0090000000000001,
        "systemFlags" : 1,
        "userFlags" : 1,
        "totalIndexSize" : 17563699552,
        "indexSizes" : {
                "_id_" : 1449596624,
                "bokey_1" : 3597717984,
                "categoryBokey_1" : 2737545552,
                "mappedCatalogCategory_1" : 1780765504,
                "clickCount_1" : 1037501696,
                "missingSince_1" : 1339891056,
                "shopId_1_merchantId_1" : 2271668896,
                "asin_1" : 533647520,
                "importGroup_1_importId_1_missingSince_1" : 834442560,
                "shopId_1__id_1" : 1980922160
        },
        "ok" : 1
}

However, db.offer.stats().userFlags is still 1, meaning that powerOf2Sizes is still used:

offerStoreDE5:SECONDARY> db.offer.stats()
{
        "ns" : "offerStore.offer",
        "count" : 55902199,
        "size" : 146841155952,
        "avgObjSize" : 2626,
        "storageSize" : 150970108880,
        "numExtents" : 91,
        "nindexes" : 10,
        "lastExtentSize" : 2146426864,
        "paddingFactor" : 1,
        "systemFlags" : 1,
        "userFlags" : 1,
        "totalIndexSize" : 17563740432,
        "indexSizes" : {
                "_id_" : 1449596624,
                "bokey_1" : 3597742512,
                "categoryBokey_1" : 2737578256,
                "mappedCatalogCategory_1" : 1780806384,
                "clickCount_1" : 1037518048,
                "missingSince_1" : 1339882880,
                "shopId_1_merchantId_1" : 2271652544,
                "asin_1" : 533663872,
                "importGroup_1_importId_1_missingSince_1" : 834377152,
                "shopId_1__id_1" : 1980922160
        },
        "ok" : 1
}

So I executed the other command I've found in the doc to switch back to the old memory allocation strategy:

root@s488:/home/admin# mongod --setParameter newCollectionsUsePowerOf2Sizes=false
2014-07-13T19:05:17.500+0200 [initandlisten] MongoDB starting : pid=58356 port=27017 dbpath=/data/db 64-bit host=s488
2014-07-13T19:05:17.501+0200 [initandlisten]
2014-07-13T19:05:17.501+0200 [initandlisten] ** WARNING: You are running on a NUMA machine.
2014-07-13T19:05:17.501+0200 [initandlisten] **          We suggest launching mongod like this to avoid performance problems:
2014-07-13T19:05:17.501+0200 [initandlisten] **              numactl --interleave=all mongod [other options]
2014-07-13T19:05:17.517+0200 [initandlisten]
2014-07-13T19:05:17.517+0200 [initandlisten] db version v2.6.1
2014-07-13T19:05:17.517+0200 [initandlisten] git version: 4b95b086d2374bdcfcdf2249272fb552c9c726e8
2014-07-13T19:05:17.517+0200 [initandlisten] build info: Linux build14.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-07-13T19:05:17.517+0200 [initandlisten] allocator: tcmalloc
2014-07-13T19:05:17.517+0200 [initandlisten] options: { setParameter: { newCollectionsUsePowerOf2Sizes: "false" } }
2014-07-13T19:05:17.529+0200 [initandlisten] exception in initAndListen: 10296
*********************************************************************
 ERROR: dbpath (/data/db) does not exist.
 Create this directory or give existing directory in --dbpath.
 See http://dochub.mongodb.org/core/startingandstoppingmongo
*********************************************************************
, terminating
2014-07-13T19:05:17.529+0200 [initandlisten] dbexit:
2014-07-13T19:05:17.529+0200 [initandlisten] shutdown: going to close listening sockets...
2014-07-13T19:05:17.529+0200 [initandlisten] shutdown: going to flush diaglog...
2014-07-13T19:05:17.529+0200 [initandlisten] shutdown: going to close sockets...
2014-07-13T19:05:17.529+0200 [initandlisten] shutdown: waiting for fs preallocator...
2014-07-13T19:05:17.529+0200 [initandlisten] shutdown: lock for final commit...
2014-07-13T19:05:17.529+0200 [initandlisten] shutdown: final commit...
2014-07-13T19:05:17.529+0200 [initandlisten] shutdown: closing all files...
2014-07-13T19:05:17.529+0200 [initandlisten] closeAllFiles() finished
2014-07-13T19:05:17.529+0200 [initandlisten] dbexit: really exiting now
root@s488:/home/admin# ps aux|grep mongo
mongodb   12808 17.5 79.0 205348560 104490476 ? Sl   Jul11 518:38 /usr/bin/mongod --config /etc/mongod_mongod.conf
root      58384  0.0  0.0  14760   920 pts/0    S+   19:05   0:00 grep mongo
root@s488:/home/admin# 

I'm also wondering why mongo is looking for /data/db because our dbPath is configured /data/mongod/db (see above the log when the server restarted).
Furthermore, the mongod process was and is still running even though mongod pretended "dbexit: really exiting now".

My main question is, how can I revert to the old memory allocation strategy? Neither config entry nor mongo shell command nor mongod command seems to work.



 Comments   
Comment by Kay Agahd [ 27/Jul/14 ]

asya I've opened the ticket to discuss my last comment: https://jira.mongodb.org/browse/SERVER-14705

Comment by Asya Kamsky [ 27/Jul/14 ]

kay.agahd@idealo.de would you open a SUPPORT ticket to discuss your last comment? I'm not certain if I agree with your conclusion but I want to make sure that I'm checking the right data - would you provide (in that ticket) the details of your observations, which nodes in your cluster had which settings during which time periods and I can see in MMS whether it's showing something different than what I would expect.

We can then open an appropriate ticket (DOCS or SERVER) depending on what we discover.

Comment by Kay Agahd [ 15/Jul/14 ]

Confirmed! The above collMod command did the trick, After having issued the command, I stopped mongod of one replSet member, emptied its dbPath folder and restarted it. Now it's in sync again with the other replSet members and the memory consumption is as low as usual by not using powerOf2Sizes.

Btw., we have monitored the memory consumption on a shards and replSet members running with and without powerOf2Sizes over a few weeks. It shows that memory consumption of powerOf2Sizes nodes is constantly round about 20% higher than on the other nodes. I can post screenshots if you're interested. Perhaps it's just due to our use case(s) that powerOf2Sizes performs so poorly but you should know and communicate that powerOf2Sizes might have a huge negative performance impact for other users of mongodb who are using the defaults since v2.6.

Comment by Kay Agahd [ 15/Jul/14 ]

I think I've found it. The collMod command needs to be executed on the primary of the replSet:

offerStoreDE5:PRIMARY> db.runCommand( {"collMod" : "offer" , "usePowerOf2Sizes" : false } )
{ "usePowerOf2Sizes_old" : true, "usePowerOf2Sizes_new" : false, "ok" : 1 }
offerStoreDE5:PRIMARY> db.offer.stats()
{
	"ns" : "offerStore.offer",
	"count" : 56434250,
	"size" : 134026250224,
	"avgObjSize" : 2374,
	"storageSize" : 147157888000,
	"numExtents" : 89,
	"nindexes" : 10,
	"lastExtentSize" : 2146426864,
	"paddingFactor" : 1,
	"systemFlags" : 1,
	"userFlags" : 0,
	"totalIndexSize" : 20964236944,
	"indexSizes" : {
		"_id_" : 1640751504,
		"bokey_1" : 4250440768,
		"categoryBokey_1" : 3354015952,
		"mappedCatalogCategory_1" : 2043288688,
		"clickCount_1" : 1350274576,
		"missingSince_1" : 1673283808,
		"shopId_1_merchantId_1" : 2736678896,
		"asin_1" : 599701424,
		"importGroup_1_importId_1_missingSince_1" : 1087963968,
		"shopId_1__id_1" : 2227837360
	},
	"ok" : 1
}


I'm just wondering what the other commands were good for:

db.getSiblingDB('admin').runCommand( { setParameter: 1, newCollectionsUsePowerOf2Sizes: false }

and

mongod --setParameter newCollectionsUsePowerOf2Sizes=false

Does the first command only change the memory allocation model for db "admin"? Or is it kind of an admin command so that all following newly created collections will not use powerOf2Sizes? Is this true also for the second command, respectivly parameter?

I'm sorry to say but mongdb's documentation is not only incomplete but also confusing us. However, thanks to your helpful pointers in this thread we might have found the solution eventually.

Comment by Kay Agahd [ 15/Jul/14 ]

Eric, ok, I only now understand that the mongod command mongod --setParameter newCollectionsUsePowerOf2Sizes=false was meant to start the mongod. The mongodb documentation at http://docs.mongodb.org/manual/reference/parameters/#param.newCollectionsUsePowerOf2Sizes is misleading because it says that you can issue the command at run-time. So I wrongly understood that this command will pass the parameter newCollectionsUsePowerOf2Sizes to an already running mongod process (on the same host). However, in reality, you need to shut down the running mongod and start it with the above command.
Well, I restarted the mongod with a config file containing

setParameter=newCollectionsUsePowerOf2Sizes=false

On the other two replSet members I executed the collMod command

db.getSiblingDB('admin').runCommand( { setParameter: 1, newCollectionsUsePowerOf2Sizes: false } 

However, the nodes are sill using powerOf2Sizes.

We can't simply drop the collection as you've suggested because the replSet is part of a sharded cluster. Making a backup of the collection, drop it, and restore it would imply a long time to be offline.
How to deal with it?

Comment by Eric Milkie [ 15/Jul/14 ]

Kay, according to the logs you posted, it says you started one of those instances with a config file that seems to have overridden the default dbpath, and for the other instance you provided no such config file. I don't think the --setParameter part is related to that behavior.

Please give more details on which command you ran on which members and what the result was. If you used collMod to change the collection metadata, it should have be replicated in an initial sync.

Comment by Kay Agahd [ 15/Jul/14 ]

The issue is closed because "works as designed"?
What's about the mongod command mongod --setParameter newCollectionsUsePowerOf2Sizes=false which picks up a wrong dbPath (see my comment above)?
Btw. I executed the command on all three replSet members, did an initial sync of one of them but it's still using powerOf2Sizes. If this works as designed, it would mean that one can't revert a replica set of a sharded cluster from powerOf2Sized back to the normal memory allocation strategy.

Comment by Kay Agahd [ 14/Jul/14 ]

Sorry, I don't understand the workflow how to revert to the normal memory allocation strategy.
As I described in CS-13109, the whole shard system was upgraded from v2.4 to v2.6, which was still running with the normal memory allocation strategy. As one of the replSet members crashed, we had to setup the server from zero. Since then, this repaired replSet member uses powerOfSizes because it's the default memory allocation strategy since v2.6 and we didn't have yet setParameter=newCollectionsUsePowerOf2Sizes=false in our config.
How can I bring back this replSet member to not use powerOf2Sizes?

Comment by Eric Milkie [ 14/Jul/14 ]

You can't do it that way. Replication is designed to copy all of the data, including metadata about the collections it replicates. The collmod command itself is replicated too, so if you change allocation strategies on a pre-existing collection, any new record sizes will be affected and will replicate respectively.

Comment by Kay Agahd [ 14/Jul/14 ]

PS: I know that doing an initial sync is not equivalent to dropping a collection. I meant rather whether my workflow would trigger the old memory allocation strategy.

Comment by Kay Agahd [ 14/Jul/14 ]

Here is what I did: I stopped mongod, modified its config by adding the line setParameter=newCollectionsUsePowerOf2Sizes=false, then deleted the whole content of the dbPath folder /data/mongod/db and started mongod again. Mongod did its initial sync with success but userFlags was still set to 1. Is this equivalent to dropping a collection?
I don't think that I'm able to drop the collection since the mongod is a secondary member of a replSet. Do I need to execute the command on the primary even though the primary is still running with the conventional memory allocation strategy (see also https://jira.mongodb.org/browse/CS-13109 )?

Comment by Ramon Fernandez Marina [ 14/Jul/14 ]

I'm not able to reproduce this behavior; using

setParameter=newCollectionsUsePowerOf2Sizes=false

in the configuration file, or the YAML equivalent:

setParameter: {newCollectionsUsePowerOf2Sizes: false}

produces the expected results. Note that this command does exactly what it says on the tin, so collections created using powerOf2Sizes are not affected when setting this parameter. Did you drop the offer collection? For example:

> db.foo.drop()
true
> db.foo.insert({x:1})
WriteResult({ "nInserted" : 1 })
> db.foo.stats()
{
        "ns" : "test.foo",
        "count" : 1,
        "size" : 48,
        "avgObjSize" : 48,
        "storageSize" : 8192,
        "numExtents" : 1,
        "nindexes" : 1,
        "lastExtentSize" : 8192,
        "paddingFactor" : 1,
        "systemFlags" : 1,
        "userFlags" : 1,
        "totalIndexSize" : 8176,
        "indexSizes" : {
                "_id_" : 8176
        },
        "ok" : 1
}
> db.getSiblingDB('admin').runCommand({setParameter : 1, newCollectionsUsePowerOf2Sizes : false})
{ "was" : true, "ok" : 1 }
> db.foo.drop()
true
> db.foo.insert({x:1})
WriteResult({ "nInserted" : 1 })
> db.foo.stats()
{
        "ns" : "test.foo",
        "count" : 1,
        "size" : 36,
        "avgObjSize" : 36,
        "storageSize" : 8192,
        "numExtents" : 1,
        "nindexes" : 1,
        "lastExtentSize" : 8192,
        "paddingFactor" : 1,
        "systemFlags" : 1,
        "userFlags" : 0,
        "totalIndexSize" : 8176,
        "indexSizes" : {
                "_id_" : 8176
        },
        "ok" : 1
}

Bottom line, you need to re-create your collections to change the memory allocation strategy. I see you're checking on a secondary, so I get the feeling we're not seeing the whole picture here. Can you please re-try dropping and re-creating your collections and let us know what userFlags has to say?

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