[SERVER-13454] 2.6 remove writeCmd regression (baseline: 2.4 remove writeOps + GLE) Created: 02/Apr/14  Updated: 10/Dec/14  Resolved: 01/May/14

Status: Closed
Project: Core Server
Component/s: Querying, Write Ops
Affects Version/s: 2.6.0-rc2
Fix Version/s: None

Type: Bug Priority: Major - P3
Reporter: Davide Italiano Assignee: Greg Studer
Resolution: Done Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Attachments: File legacy_writes_profile.csv     File remove-24.py     File remove-26.py     File write_commands_profile.csv     File writecmd.cpp     File writeops.cpp    
Operating System: ALL
Participants:

 Description   

About 50% slower in my synthetic scenario. The only difference is that (I guess) 2.4 relies on writeOps + GLE while 2.6 uses writeCmd (and so, in my test I didn't call GLE after remove() call).

2.6 testcase:

db.dropDatabase();
 
var ndocs = 20000;
 
 
for (var i = 0; i < ndocs; ++i) {
    db.foo.insert({"a": i});
}
 
db.foo.ensureIndex({"a": 1});
 
var before = new Date().getTime();
for (var i = 0; i < ndocs; ++i) {
    db.foo.remove({"a": i});
}
print(new Date().getTime() - before);

2.6 results (githash ad91eb0f75f39c1bb71b5e0ca4279b883cb9fe8d ):

$ for i in `seq 1 5`; do ./mongo remove-26.js |grep ^[0-9]; done
4941
4937
4952
4932
4936

2.4 testcase:

db.dropDatabase();
 
var ndocs = 20000;
 
for (var i = 0; i < ndocs; ++i) {
    db.foo.insert({"a": i});
}
 
db.foo.ensureIndex({"a": 1});
 
var before = new Date().getTime();
for (var i = 0; i < ndocs; ++i) {
    db.foo.remove({"a": i});
    db.getLastError();
}
print(new Date().getTime() - before);

2.4 results:

$ for i in `seq 1 5`; do ./mongo remove-24.js |grep ^[0-9]; done
2782
2741
2737
2751
2755



 Comments   
Comment by Greg Studer [ 01/May/14 ]

Resolving as "Javascript write commands are slooow"

Comment by Greg Studer [ 07/Apr/14 ]

> Apparently the shell is awfully slow at building the commands, unless I'm missing something. Maybe the title of this ticket should be rephrased to reflect this new problem (if you consider this a problem).

Yeah, it is - I'm not sure we care that much for now? No one should really be using the shell underneath an application - and if doing a lot of writes the batching should amortize the costs.

David mentioned that he still saw regressions using the python driver - wonder if this is due to the same overhead. Ideally we could keep investigating, but IMO this is lower priority than more realistic write command tests.

Comment by Davide Italiano [ 04/Apr/14 ]

I tested with the C and C++ driver to confirm it was a client-side issue rather than a server side issue, code attached.

WriteOps results (against a 2.6 mongod):

$ for i in `seq 1 5`; do ./writeops; done8.398115
8.288431
8.303667
8.308958
8.307844

WriteOps results (against a 2.4 mongod):

$ for i in `seq 1 5`; do ./writeops; done
8.767040
8.767775
8.882403
8.768063
8.681774

WriteCmd results (against a 2.6 mongod):

$ for i in `seq 1 5`; do ./writecmd; done
8.177082
8.157141
8.243254
8.213866
8.207350

The numbers do not show any evident regression in the new write path actually, and 2.6 is slightly faster than 2.4 in this scenario.

Back to the Javascript shell I changed the script in this ticket to manually writing write commands instead of using the remove() helper in this way.

db.runCommand({"delete": "foo", "deletes" : [{ "q": {"a": i}, "limit" : 0} ]});

instead of

db.foo.remove({"a": i});

Results (hand-rolled write commands):

$ for i in `seq 1 5`; do ./mongo remove-26.js | grep ^[0-9]; done 
3045
3052
3064
3015
3107

Results(helper):

 
for i in `seq 1 5`; do ./mongo remove-26.js | grep ^[0-9]; done 
4945
4942
4900
4914
4956

Apparently the shell is awfully slow at building the commands, unless I'm missing something. Maybe the title of this ticket should be rephrased to reflect this new problem (if you consider this a problem).

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