-
Type: Bug
-
Resolution: Incomplete
-
Priority: Major - P3
-
None
-
Affects Version/s: None
-
Component/s: Build
-
Build
-
ALL
Some test logs contain a large number of blank lines. e.g. <http://buildlogs.mongodb.org/mci_0.9_windows_32/builds/33297/test/jsCore_compatibility_0/splitvector.js?mode=raw> (also attached to ticket).
~95% of lines in the above test output are blank:
rassi@laptop:~/work/mongo $ grep '^$' splitvector_js_test_output.txt | wc -l
3974
rassi@laptop:~/work/mongo $ wc -l splitvector_js_test_output.txt
4099 splitvector_js_test_output.txt
rassi@laptop:~/work/mongo $
The blank lines seem to appear after the test finishes:
2014-03-20T22:23:23.358+0000 [conn60] build index on: test.jstests_splitvector properties: { v: 1, key: { _id: 1 }, name: "_id_", ns: "test.jstests_splitvector" } 2014-03-20T22:23:23.358+0000 [conn60] added index to empty collection 2014-03-20T22:23:23.359+0000 [conn60] build index on: test.jstests_splitvector properties: { v: 1, key: { x: 1.0, y: -1.0, z: 1.0 }, name: "x_1_y_-1_z_1", ns: "test.jstests_splitvector" } 2014-03-20T22:23:23.359+0000 [conn60] added index to empty collection 2014-03-20T22:23:25.409+0000 [conn60] request split points lookup for chunk test.jstests_splitvector { : MinKey, : MaxKey, : MinKey } -->> { : MaxKey, : MinKey, : MaxKey } test.jstests_splitvector test.jstests_splitvector PASSED
It looks like buildlogger.py is getting the blank lines from the shell stdout (it's entirely unclear why the shell would be generating them):
> db.logs.find({build_id:ObjectId("532b64add2a60f7ad7000543"),test_id:ObjectId("532b6a30d2a60f0511000b1f")}).sort({seq:1}).limit(1).skip(0).pretty() { "_id" : ObjectId("532b6a3fd2a60f0511000b9e"), "build_id" : ObjectId("532b64add2a60f7ad7000543"), "test_id" : ObjectId("532b6a30d2a60f0511000b1f"), "lines" : [ [ ISODate("2014-03-20T22:22:40.401Z"), "MongoDB shell version: 2.6.0-rc2-pre-" ], [ ISODate("2014-03-20T22:22:40.454Z"), "connecting to: 127.0.0.1:27999/test" ], [ ISODate("2014-03-20T22:22:40.459Z"), "D:\\data\\db/" ], [ ISODate("2014-03-20T22:22:55.045Z"), "test.jstests_splitvector" ] ], "seq" : 1 } > db.logs.find({build_id:ObjectId("532b64add2a60f7ad7000543"),test_id:ObjectId("532b6a30d2a60f0511000b1f")}).sort({seq:1}).limit(1).skip(1).pretty() { "_id" : ObjectId("532b6a5dd2a60f0566000b1c"), "build_id" : ObjectId("532b64add2a60f7ad7000543"), "test_id" : ObjectId("532b6a30d2a60f0511000b1f"), "lines" : [ [ ISODate("2014-03-20T22:23:25.425Z"), "test.jstests_splitvector" ] ], "seq" : 2 } > db.logs.find({build_id:ObjectId("532b64add2a60f7ad7000543"),test_id:ObjectId("532b6a30d2a60f0511000b1f")}).sort({seq:1}).limit(1).skip(i++).pretty() { "_id" : ObjectId("532b6a5dd2a60f067b00026d"), "build_id" : ObjectId("532b64add2a60f7ad7000543"), "test_id" : ObjectId("532b6a30d2a60f0511000b1f"), "lines" : [ [ ISODate("2014-03-20T22:23:25.445Z"), "test.jstests_splitvector" ], [ ISODate("2014-03-20T22:23:25.445Z"), "PASSED" ], [ ISODate("2014-03-20T22:23:25.448Z"), "" ], [ ISODate("2014-03-20T22:23:25.448Z"), "" ], [ ISODate("2014-03-20T22:23:25.448Z"), "" ], <snip>
This seems to affect ~1% of tests in buildlogger (that is, ~1% of tests contain at least 1000 blank lines):
> db.logs.aggregate([{$limit:100000},{$unwind:'$lines'},{$match:{"lines.1":""}},{$group:{_id:{build_id:'$build_id',test_id:'$test_id'},count:{$sum:1}}},{$match:{count:{$gt:1000}}}]).result.length 985