Details
-
Task
-
Resolution: Works as Designed
-
Major - P3
-
None
-
3.6.3
-
None
-
OS 3.10.0-693.21.1.el7.x86_64 #1 SMP Wed Mar 7 19:03:37 UTC 2018 x86_64 x86_64 x86_64 GNU/Linux
MongoDB 3.4.12 (with Replica-set)
Java driver 3.6.3
Description
With mongo client, we can see disk write operation for journal sync with writeconcern({w:1,j:true}).
for(var idx=0; idx<1000000; idx++){ |
db.wctest.insert({ "someKey" : "someValue" }, { writeConcern: { w: 1, j:true } }); |
}
|
|
|
$ iostat -dxk 1 |
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
|
sda 0.00 10.00 0.00 3217.00 0.00 13025.00 8.10 0.09 0.03 0.00 0.03 0.03 8.90 |
sda 0.00 0.00 0.00 3126.00 0.00 12596.00 8.06 0.09 0.03 0.00 0.03 0.03 8.90 |
sda 0.00 0.00 0.00 3154.00 0.00 12710.50 8.06 0.09 0.03 0.00 0.03 0.03 9.30 |
sda 0.00 0.00 0.00 3181.00 0.00 12817.50 8.06 0.08 0.03 0.00 0.03 0.03 8.10 |
sda 0.00 0.00 3.00 3230.00 24.00 13025.50 8.07 0.10 0.03 0.33 0.03 0.03 9.50 |
sda 0.00 0.00 3.00 3171.00 24.00 12777.50 8.07 0.10 0.03 0.00 0.03 0.03 9.60 |
|
|
$ mongostat
|
insert query update delete getmore command dirty used flushes vsize res qrw arw net_in net_out conn set repl time
|
2873 *0 *0 *0 674 1301|0 0.1% 2.9% 1 1.73G 340M 0|0 1|0 1.52m 1.47m 9 journaltest PRI May 2 17:03:05.489 |
2952 *0 *0 *0 683 1326|0 0.1% 2.9% 0 1.73G 341M 0|0 1|0 1.55m 1.50m 9 journaltest PRI May 2 17:03:06.489 |
2959 *0 *0 *0 680 1317|0 0.2% 2.9% 0 1.76G 342M 0|0 1|0 1.54m 1.50m 9 journaltest PRI May 2 17:03:07.490 |
2986 *0 *0 *0 686 1331|0 0.2% 2.9% 0 1.76G 343M 0|0 1|1 1.56m 1.51m 9 journaltest PRI May 2 17:03:08.489 |
And journal false writeconcern also.
for(var idx=0; idx<1000000; idx++){ |
db.wctest.insert({ "someKey" : "someValue" }, { writeConcern: { w: 1, j:false } }); |
}
|
|
|
$ iostat -dxk 1 |
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
|
sda 0.00 0.00 0.00 16.00 0.00 1182.00 147.75 0.00 0.12 0.00 0.12 0.12 0.20 |
sda 0.00 0.00 0.00 6.00 0.00 985.00 328.33 0.00 0.50 0.00 0.50 0.50 0.30 |
sda 0.00 5.00 0.00 17.00 0.00 1068.00 125.65 0.00 0.12 0.00 0.12 0.12 0.20 |
sda 0.00 0.00 0.00 6.00 0.00 977.00 325.67 0.00 0.33 0.00 0.33 0.33 0.20 |
sda 0.00 0.00 0.00 6.00 0.00 985.00 328.33 0.00 0.33 0.00 0.33 0.33 0.20 |
sda 0.00 0.00 0.00 6.00 0.00 978.50 326.17 0.00 0.33 0.00 0.33 0.33 0.20 |
sda 0.00 0.00 0.00 6.00 0.00 989.00 329.67 0.00 0.33 0.00 0.33 0.33 0.20 |
|
|
$ mongostat
|
insert query update delete getmore command dirty used flushes vsize res qrw arw net_in net_out conn set repl time
|
3768 *0 *0 *0 684 1310|0 0.4% 3.2% 0 1.76G 376M 0|0 1|0 1.68m 1.80m 9 journaltest PRI May 2 17:04:48.351 |
3808 *0 *0 *0 681 1316|0 0.4% 3.3% 0 1.79G 378M 0|0 1|0 1.69m 1.82m 9 journaltest PRI May 2 17:04:49.351 |
3845 *0 *0 *0 677 1299|0 0.4% 3.3% 0 1.79G 379M 0|0 2|0 1.68m 1.82m 9 journaltest PRI May 2 17:04:50.352 |
3743 *0 *0 *0 681 1321|0 0.4% 3.3% 0 1.79G 381M 0|0 1|0 1.68m 1.79m 9 journaltest PRI May 2 17:04:51.350 |
3637 *0 *0 *0 680 1303|0 0.4% 3.3% 0 1.82G 382M 0|0 1|0 1.65m 1.75m 9 journaltest PRI May 2 17:04:52.350 |
3680 *0 *0 *0 684 1314|0 0.4% 3.3% 0 1.82G 384M 0|0 1|0 1.66m 1.77m 9 journaltest PRI May 2 17:04:53.350 |
|
But with java client driver, looks like no disk operations for journal sync even I set WriteConcern.JOURNALED writeconcern. And I have traced disk io system call with strace, but there's no sync operation. Below is simple test program I have used.
public class WriteConcernJournalTester { |
private static final Logger log = Logger.getAnonymousLogger(); |
|
public static void main(String[] args) throws Exception { |
WriteConcernJournalTester tester = new WriteConcernJournalTester(); |
|
boolean withJournal = Boolean.getBoolean(args[0]); |
tester.run(withJournal);
|
}
|
|
private void run(boolean withJournal) throws Exception{ |
MongoCollection<Document> collection = getCollection("perftest", withJournal); |
log.info("Elapsed : " + insertRecords(collection, withJournal)); |
}
|
|
private long insertRecords(MongoCollection<Document> collection, boolean withJournal) { |
long startTime=System.currentTimeMillis(); |
for(int i=0;i<1000000;i++){ |
collection.insertOne(new Document("someKey", "someValue")); |
}
|
|
long endTime=System.currentTimeMillis(); |
collection.drop();
|
return (endTime-startTime); |
} private MongoCollection<Document> getCollection(String databaseName, boolean withJournal) throws Exception{ |
MongoClient conn = new MongoClient(new MongoClientURI("mongodb://node1:27017,node2:27017/?replicaSet=journaltest")); |
if(withJournal){ |
WriteConcern wc = WriteConcern.W1.withJournal(true); |
// WriteConcern wc = WriteConcern.ACKNOWLEDGED.withJournal(true); |
return conn.getDatabase("perftest").getCollection("perftest").withWriteConcern(wc); |
}else{ |
WriteConcern wc = WriteConcern.W1.withJournal(false); |
// WriteConcern wc = WriteConcern.ACKNOWLEDGED.withJournal(false); |
return conn.getDatabase("perftest").getCollection("perftest").withWriteConcern(wc); |
}
|
}
|
}
|
for both "WriteConcern.W1.withJournal(true)" and "WriteConcern.ACKNOWLEDGED.withJournal(true)", looks like mongod does not sync journal log for each write operation. Disk write operations is almost same as "{w:1, f:false}" in mongo client.