|
That fix seems to have resolved the issue with 'tmpTree.' Woohoo! I unfortunately got a new failure:
[j0] {"t":{"$date":"2021-05-26T14:48:35.818+00:00"},"s":"I", "c":"-", "id":20162, "ctx":"js","msg":"{jsPrint}","attr":{"jsPrint":"[ \"Function\", \"Object\", \"eval\", \"sleep\", \"gc\", \"print\", \"version\", \"buildInfo\", \"getJSHeapLimitMB\", \"undefined\", \"Array\", \"Boolean\", \"JSON\", \"Date\", \"Math\", \"isNaN\", \"isFinite\", \"parseInt\", \"parseFloat\", \"NaN\", \"Infinity\", \"Number\", \"escape\", \"unescape\", \"uneval\", \"decodeURI\", \"encodeURI\", \"decodeURIComponent\", \"encodeURIComponent\", \"String\", \"RegExp\", \"Error\", \"InternalError\", \"EvalError\", \"RangeError\", \"ReferenceError\", \"SyntaxError\", \"TypeError\", \"URIError\", \"ArrayBuffer\", \"Int8Array\", \"Uint8Array\", \"Int16Array\", \"Uint16Array\", \"Int32Array\", \"Uint32Array\", \"Float32Array\", \"Float64Array\", \"Uint8ClampedArray\", \"Proxy\", \"WeakMap\", \"Set\", \"DataView\", \"Symbol\", \"WeakSet\", \"Promise\", \"WebAssembly\", \"BinData\", \"HexData\", \"MD5\", \"UUID\", \"bsonWoCompare\", \"bsonUnorderedFieldsCompare\", \"bsonBinaryEqual\", \"bsonObjToArray\", \"Code\", \"DBPointer\", \"DBRef\", \"MaxKey\", \"MinKey\", \"NumberInt\", \"NumberLong\", \"NumberDecimal\", \"ObjectId\", \"Timestamp\", \"MongoURI\", \"_convertExceptionToReturnStatus\", \"doassert\", \"sortDoc\", \"assert\", \"__lastres__\", \"ISODate\", \"Map\", \"tojsononeline\", \"tojson\", \"tojsonObject\", \"printjson\", \"printjsononeline\", \"isString\", \"isNumber\", \"isObject\", \"hex_md5\", \"tostrictjson\", \"obj\", \"fullObject\", \"__returnValue\", \"x\" ]"},"tags":["plainShellOutput"]}
|
[j0] {"t":{"$date":"2021-05-26T14:48:35.818+00:00"},"s":"I", "c":"-", "id":20162, "ctx":"js","msg":"{jsPrint}","attr":{"jsPrint":"[ \"Array\", \"ArrayBuffer\", \"BinData\", \"Boolean\", \"Code\", \"DBPointer\", \"DBRef\", \"DataView\", \"Date\", \"Error\", \"EvalError\", \"Float32Array\", \"Float64Array\", \"Function\", \"HexData\", \"ISODate\", \"Infinity\", \"Int16Array\", \"Int32Array\", \"Int8Array\", \"InternalError\", \"JSON\", \"MD5\", \"Map\", \"Math\", \"MaxKey\", \"MinKey\", \"MongoURI\", \"NaN\", \"Number\", \"NumberDecimal\", \"NumberInt\", \"NumberLong\", \"Object\", \"ObjectId\", \"Promise\", \"Proxy\", \"RangeError\", \"ReferenceError\", \"RegExp\", \"Set\", \"String\", \"Symbol\", \"SyntaxError\", \"Timestamp\", \"TypeError\", \"URIError\", \"UUID\", \"Uint16Array\", \"Uint32Array\", \"Uint8Array\", \"Uint8ClampedArray\", \"WeakMap\", \"WeakSet\", \"WebAssembly\", \"__lastres__\", \"_convertExceptionToReturnStatus\", \"assert\", \"bsonBinaryEqual\", \"bsonObjToArray\", \"bsonUnorderedFieldsCompare\", \"bsonWoCompare\", \"buildInfo\", \"decodeURI\", \"decodeURIComponent\", \"doassert\", \"encodeURI\", \"encodeURIComponent\", \"escape\", \"eval\", \"gc\", \"getJSHeapLimitMB\", \"hex_md5\", \"isFinite\", \"isNaN\", \"isNumber\", \"isObject\", \"isString\", \"parseFloat\", \"parseInt\", \"print\", \"printjson\", \"printjsononeline\", \"sleep\", \"sortDoc\", \"tojson\", \"tojsonObject\", \"tojsononeline\", \"tostrictjson\", \"undefined\", \"unescape\", \"uneval\", \"version\", \"obj\", \"fullObject\" ]"},"tags":["plainShellOutput"]}
|
[j0] {"t":{"$date":"2021-05-26T14:48:35.819+00:00"},"s":"I", "c":"-", "id":20162, "ctx":"js","msg":"{jsPrint}","attr":{"jsPrint":"found extra item: x"},"tags":["plainShellOutput"]}
|
[j0] {"t":{"$date":"2021-05-26T14:48:35.825+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"127.0.0.1:39868","uuid":"f4e273a1-5aa8-4f48-8571-ff8d16bb9ef0","connectionId":1856,"connectionCount":60}}
|
[js_test:basic] S1 Test : jstests/core/geo_allowedcomparisons.js 180ms
|
[js_test:basic] S1 Test : jstests/core/count7.js ...
|
[j0] {"t":{"$date":"2021-05-26T14:48:35.826+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn1856","msg":"client metadata","attr":{"remote":"127.0.0.1:39868","client":"conn1856","doc":{"application":{"name":"MongoDB Shell","pid":"17397"},"driver":{"name":"MongoDB Internal Client","version":"5.0.0-alpha0-640-g69fa620-patch-60ae5521d1fe0716ddf3a362"},"os":{"type":"Linux","name":"Red Hat Enterprise Linux release 8.0 (Ootpa)","architecture":"x86_64","version":"Kernel 4.18.0-80.1.2.el8_0.x86_64"}}}}
|
[js_test:basic] Error: [1] != [0] are not equal :
|
[js_test:basic] doassert@src/mongo/shell/assert.js:20:14
|
[j0] {"t":{"$date":"2021-05-26T14:48:35.831+00:00"},"s":"W", "c":"EXECUTOR", "id":4910400, "ctx":"conn1849","msg":"Terminating session due to error","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection closed by peer"}}}
|
[j0] {"t":{"$date":"2021-05-26T14:48:35.831+00:00"},"s":"W", "c":"EXECUTOR", "id":4910400, "ctx":"conn1852","msg":"Terminating session due to error","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection closed by peer"}}}
|
[j0] {"t":{"$date":"2021-05-26T14:48:35.831+00:00"},"s":"I", "c":"NETWORK", "id":5127900, "ctx":"conn1849","msg":"Ending session","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection closed by peer"}}}
|
[j0] {"t":{"$date":"2021-05-26T14:48:35.831+00:00"},"s":"I", "c":"NETWORK", "id":5127900, "ctx":"conn1852","msg":"Ending session","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection closed by peer"}}}
|
[j0] {"t":{"$date":"2021-05-26T14:48:35.831+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn1849","msg":"Connection ended","attr":{"remote":"127.0.0.1:39854","uuid":"2fe91656-6652-4ef2-8b80-315e713b3daf","connectionId":1849,"connectionCount":59}}
|
[j0] {"t":{"$date":"2021-05-26T14:48:35.831+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn1852","msg":"Connection ended","attr":{"remote":"127.0.0.1:39860","uuid":"9fcad314-fbcb-41d8-ad48-c02398ea3733","connectionId":1852,"connectionCount":58}}
|
[js_test:basic] assert.eq@src/mongo/shell/assert.js:179:9
|
[js_test:basic] @jstests/core/js_global_scope.js:160:1
|
[js_test:basic] @jstests/core/js_global_scope.js:9:2
|
[js_test:basic] time<@eval:11:17
|
[js_test:basic] Date.timeFunc@src/mongo/shell/types.js:32:9
|
[js_test:basic] @eval:6:24
|
[js_test:basic] @eval:4:9
|
[js_test:basic] wrapper@eval:7:17
|
[js_test:basic] _threadStartWrapper@:26:16
|
[js_test:basic]
|
[js_test:basic] ********** Parallel Test FAILED: Error: error loading js file: jstests/core/js_global_scope.js
|
This one is curious - that appears to simply be a tag you can apply to log messages. There are some example log messages using this - many failing JS invocations:
[j0] {"t":{"$date":"2021-05-26T14:49:04.148+00:00"},"s":"I", "c":"QUERY", "id":20163, "ctx":"conn1948","msg":"{jsError}","attr":{"jsError":"Error: The character \\x69 failed to parse from hex. :\n@:1:29\n"},"tags":["plainShellOutput"]}
|
[j0] {"t":{"$date":"2021-05-26T14:49:05.032+00:00"},"s":"I", "c":"QUERY", "id":20163, "ctx":"js","msg":"{jsError}","attr":{"jsError":"Error: DBRef needs 2 or 3 arguments :\n@:1:22\n"},"tags":["plainShellOutput"]}
|
[j0] {"t":{"$date":"2021-05-26T14:49:05.034+00:00"},"s":"I", "c":"QUERY", "id":20163, "ctx":"js","msg":"{jsError}","attr":{"jsError":"Error: DBRef 1st parameter must be a string :\n@:1:22\n"},"tags":["plainShellOutput"]}
|
I don't understand how this log tag could make its way into the shell. Will have to keep digging.
|
|
Moving this back to open since I really haven't been able to wrap it up for quite some time now. I'll put it back on the backlog user in hopes another engineer will be able to pick it up and make some progress. The code review linked above was LGTM'ed, but every time I try to commit this a new testing problem emerges on evergreen. The latest failure I was trying to diagnose and reproduce was in the parallel suite. It seemed like somewhere a test was adding "tmpTree" to the global scope, but I wasn't able to reproduce or track down how or why this was happening:
[MongoDFixture:job0] 2021-02-13T00:16:54.140+0000 | 2021-02-13T00:16:54.138+00:00 I - 20162 [js] "{jsPrint}","attr":{"jsPrint":"[ \"Function\", \"Object\", \"eval\", \"sleep\", \"gc\", \"print\", \"version\", \"buildInfo\", \"getJSHeapLimitMB\", \"undefined\", \"Array\", \"Boolean\", \"JSON\", \"Date\", \"Math\", \"isNaN\", \"isFinite\", \"parseInt\", \"parseFloat\", \"NaN\", \"Infinity\", \"Number\", \"escape\", \"unescape\", \"uneval\", \"decodeURI\", \"encodeURI\", \"decodeURIComponent\", \"encodeURIComponent\", \"String\", \"RegExp\", \"Error\", \"InternalError\", \"EvalError\", \"RangeError\", \"ReferenceError\", \"SyntaxError\", \"TypeError\", \"URIError\", \"ArrayBuffer\", \"Int8Array\", \"Uint8Array\", \"Int16Array\", \"Uint16Array\", \"Int32Array\", \"Uint32Array\", \"Float32Array\", \"Float64Array\", \"Uint8ClampedArray\", \"Proxy\", \"WeakMap\", \"Set\", \"DataView\", \"Symbol\", \"WeakSet\", \"Promise\", \"WebAssembly\", \"BinData\", \"HexData\", \"MD5\", \"UUID\", \"bsonWoCompare\", \"bsonUnorderedFieldsCompare\", \"bsonBinaryEqual\", \"bsonObjToArray\", \"Code\", \"DBPointer\", \"DBRef\", \"MaxKey\", \"MinKey\", \"NumberInt\", \"NumberLong\", \"NumberDecimal\", \"ObjectId\", \"Timestamp\", \"MongoURI\", \"_convertExceptionToReturnStatus\", \"doassert\", \"sortDoc\", \"assert\", \"__lastres__\", \"ISODate\", \"Map\", \"tojsononeline\", \"tojson\", \"tojsonObject\", \"printjson\", \"printjsononeline\", \"isString\", \"isNumber\", \"isObject\", \"hex_md5\", \"tostrictjson\", \"tmpTree\", \"obj\", \"fullObject\", \"__returnValue\" ]"}
|
[MongoDFixture:job0] 2021-02-13T00:16:54.140+0000 | 2021-02-13T00:16:54.138+00:00 I - 20162 [js] "{jsPrint}","attr":{"jsPrint":"[ \"Array\", \"ArrayBuffer\", \"BinData\", \"Boolean\", \"Code\", \"DBPointer\", \"DBRef\", \"DataView\", \"Date\", \"Error\", \"EvalError\", \"Float32Array\", \"Float64Array\", \"Function\", \"HexData\", \"ISODate\", \"Infinity\", \"Int16Array\", \"Int32Array\", \"Int8Array\", \"InternalError\", \"JSON\", \"MD5\", \"Map\", \"Math\", \"MaxKey\", \"MinKey\", \"MongoURI\", \"NaN\", \"Number\", \"NumberDecimal\", \"NumberInt\", \"NumberLong\", \"Object\", \"ObjectId\", \"Promise\", \"Proxy\", \"RangeError\", \"ReferenceError\", \"RegExp\", \"Set\", \"String\", \"Symbol\", \"SyntaxError\", \"Timestamp\", \"TypeError\", \"URIError\", \"UUID\", \"Uint16Array\", \"Uint32Array\", \"Uint8Array\", \"Uint8ClampedArray\", \"WeakMap\", \"WeakSet\", \"WebAssembly\", \"__lastres__\", \"_convertExceptionToReturnStatus\", \"assert\", \"bsonBinaryEqual\", \"bsonObjToArray\", \"bsonUnorderedFieldsCompare\", \"bsonWoCompare\", \"buildInfo\", \"decodeURI\", \"decodeURIComponent\", \"doassert\", \"encodeURI\", \"encodeURIComponent\", \"escape\", \"eval\", \"gc\", \"getJSHeapLimitMB\", \"hex_md5\", \"isFinite\", \"isNaN\", \"isNumber\", \"isObject\", \"isString\", \"parseFloat\", \"parseInt\", \"print\", \"printjson\", \"printjsononeline\", \"sleep\", \"sortDoc\", \"tojson\", \"tojsonObject\", \"tojsononeline\", \"tostrictjson\", \"undefined\", \"unescape\", \"uneval\", \"version\", \"obj\", \"fullObject\" ]"}
|
[MongoDFixture:job0] 2021-02-13T00:16:54.140+0000 | 2021-02-13T00:16:54.140+00:00 I - 20162 [js] "{jsPrint}","attr":{"jsPrint":"found extra item: tmpTree"}
|
[js_test:basicPlus] 2021-02-13T00:16:54.147+0000 assert: [1] != [0] are not equal
|
[js_test:basicPlus] 2021-02-13T00:16:54.147+0000 doassert@src/mongo/shell/assert.js:20:14
|
[js_test:basicPlus] 2021-02-13T00:16:54.147+0000 assert.eq@src/mongo/shell/assert.js:179:9
|
[js_test:basicPlus] 2021-02-13T00:16:54.147+0000 @jstests/core/js_global_scope.js:160:1
|
[js_test:basicPlus] 2021-02-13T00:16:54.147+0000 @jstests/core/js_global_scope.js:9:2
|
[js_test:basicPlus] 2021-02-13T00:16:54.147+0000 time<@eval:11:17
|
[js_test:basicPlus] 2021-02-13T00:16:54.148+0000 Date.timeFunc@src/mongo/shell/types.js:32:9
|
[js_test:basicPlus] 2021-02-13T00:16:54.149+0000 @eval:6:24
|
[js_test:basicPlus] 2021-02-13T00:16:54.149+0000 @eval:4:9
|
[js_test:basicPlus] 2021-02-13T00:16:54.149+0000 wrapper@eval:7:17
|
[js_test:basicPlus] 2021-02-13T00:16:54.149+0000 _threadStartWrapper@:26:16
|
[js_test:basicPlus] 2021-02-13T00:16:54.149+0000 Error: [1] != [0] are not equal :
|
[js_test:basicPlus] 2021-02-13T00:16:54.149+0000 doassert@src/mongo/shell/assert.js:20:14
|
[js_test:basicPlus] 2021-02-13T00:16:54.149+0000 assert.eq@src/mongo/shell/assert.js:179:9
|
[js_test:basicPlus] 2021-02-13T00:16:54.149+0000 @jstests/core/js_global_scope.js:160:1
|
[js_test:basicPlus] 2021-02-13T00:16:54.149+0000 @jstests/core/js_global_scope.js:9:2
|
[js_test:basicPlus] 2021-02-13T00:16:54.149+0000 time<@eval:11:17
|
[js_test:basicPlus] 2021-02-13T00:16:54.150+0000 Date.timeFunc@src/mongo/shell/types.js:32:9
|
[js_test:basicPlus] 2021-02-13T00:16:54.150+0000 @eval:6:24
|
[js_test:basicPlus] 2021-02-13T00:16:54.150+0000 @eval:4:9
|
[js_test:basicPlus] 2021-02-13T00:16:54.150+0000 wrapper@eval:7:17
|
[js_test:basicPlus] 2021-02-13T00:16:54.150+0000 _threadStartWrapper@:26:16
|
[js_test:basicPlus] 2021-02-13T00:16:54.150+0000
|
[js_test:basicPlus] 2021-02-13T00:16:54.150+0000 ********** Parallel Test FAILED: Error: error loading js file: jstests/core/js_global_scope.js
|
You can see this failure in my patch build here.
|