[SERVER-47816] Log structured query plans for unittests Created: 28/Apr/20  Updated: 06/Dec/22

Status: Backlog
Project: Core Server
Component/s: None
Affects Version/s: None
Fix Version/s: None

Type: Improvement Priority: Major - P3
Reporter: Arun Banala Assignee: Backlog - Query Execution
Resolution: Unresolved Votes: 0
Labels: qexec-team
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Assigned Teams:
Query Execution
Participants:

 Description   

The logv2 format each log entry as a single line JSON object. When the log entry is supposed to be a multi-line message, they are not human readable. Maybe we can use the old log format here.

Sample error log by query_planner_test_fixture.cpp

 
{"t":{"$date":"2020-04-28T11:04:35.204Z"},"s":"E",  "c":"TEST",     "id":23070,   "ctx":"main","msg":"Throwing exception","attr":{"exception":"expected 1 matches for solution {fetch: {node: {mergeSort: {nodes: [{fetch: {filter: {b: 1}, node: {ixscan: {pattern: {a: 1}, dir: 1}}}}, {ixscan: {pattern: {a: 1}, dir: 1}}]}}}} but got 0 instead. all solutions generated: \nFETCH\n---fetched = 1\n---sortedByDiskLoc = 0\n---providedSorts = {baseSortPattern: { a: -1 }, ignoredFields: []}\n---Child:\n------MERGE_SORT\n---------fetched = 0\n---------sortedByDiskLoc = 0\n---------providedSorts = {baseSortPattern: { a: -1 }, ignoredFields: []}\n---------Child 0:\n------------FETCH\n---------------filter:\n                        b $eq 1\n---------------fetched = 1\n---------------sortedByDiskLoc = 1\n---------------providedSorts = {baseSortPattern: {}, ignoredFields: [a]}\n---------------Child:\n------------------IXSCAN\n---------------------indexName = hari_king_of_the_stove\nkeyPattern = { a: 1 }\n---------------------direction = 1\n---------------------bounds = field #0['a']: [1, 1]\n---------------------fetched = 0\n---------------------sortedByDiskLoc = 1\n---------------------providedSorts = {baseSortPattern: {}, ignoredFields: [a]}\n\n---------Child 1:\n------------IXSCAN\n---------------indexName = hari_king_of_the_stove\nkeyPattern = { a: 1 }\n---------------direction = -1\n---------------bounds = field #0['a']: (0, -inf.0]\n---------------fetched = 0\n---------------sortedByDiskLoc = 0\n---------------providedSorts = {baseSortPattern: { a: -1 }, ignoredFields: []}\n\n\nSORT\n---type = SIMPLE\n---pattern = { a: -1 }\n---limit = 0\n---fetched = 1\n---sortedByDiskLoc = 0\n---providedSorts = {baseSortPattern: {}, ignoredFields: []}\n---Child:\n------COLLSCAN\n---------ns = test.collection\n---------filter = $or\n    $and\n        a $eq 1\n        b $eq 1\n    a $lt 0\n---------fetched = 1\n---------sortedByDiskLoc = 0\n---------providedSorts = {baseSortPattern: {}, ignoredFields: []}\n\n @src/mongo/db/query/query_planner_test_fixture.cpp:521"}}
{"t":{"$date":"2020-04-28T11:04:35.205Z"},"s":"I",  "c":"TEST",     "id":4680100, "ctx":"main","msg":"FAIL","attr":{"test":"MergeSortReverseScans","type":"TestAssertionFailureException","error":"expected 1 matches for solution {fetch: {node: {mergeSort: {nodes: [{fetch: {filter: {b: 1}, node: {ixscan: {pattern: {a: 1}, dir: 1}}}}, {ixscan: {pattern: {a: 1}, dir: 1}}]}}}} but got 0 instead. all solutions generated: \nFETCH\n---fetched = 1\n---sortedByDiskLoc = 0\n---providedSorts = {baseSortPattern: { a: -1 }, ignoredFields: []}\n---Child:\n------MERGE_SORT\n---------fetched = 0\n---------sortedByDiskLoc = 0\n---------providedSorts = {baseSortPattern: { a: -1 }, ignoredFields: []}\n---------Child 0:\n------------FETCH\n---------------filter:\n                        b $eq 1\n---------------fetched = 1\n---------------sortedByDiskLoc = 1\n---------------providedSorts = {baseSortPattern: {}, ignoredFields: [a]}\n---------------Child:\n------------------IXSCAN\n---------------------indexName = hari_king_of_the_stove\nkeyPattern = { a: 1 }\n---------------------direction = 1\n---------------------bounds = field #0['a']: [1, 1]\n---------------------fetched = 0\n---------------------sortedByDiskLoc = 1\n---------------------providedSorts = {baseSortPattern: {}, ignoredFields: [a]}\n\n---------Child 1:\n------------IXSCAN\n---------------indexName = hari_king_of_the_stove\nkeyPattern = { a: 1 }\n---------------direction = -1\n---------------bounds = field #0['a']: (0, -inf.0]\n---------------fetched = 0\n---------------sortedByDiskLoc = 0\n---------------providedSorts = {baseSortPattern: { a: -1 }, ignoredFields: []}\n\n\nSORT\n---type = SIMPLE\n---pattern = { a: -1 }\n---limit = 0\n---fetched = 1\n---sortedByDiskLoc = 0\n---providedSorts = {baseSortPattern: {}, ignoredFields: []}\n---Child:\n------COLLSCAN\n---------ns = test.collection\n---------filter = $or\n    $and\n        a $eq 1\n        b $eq 1\n    a $lt 0\n---------fetched = 1\n---------sortedByDiskLoc = 0\n---------providedSorts = {baseSortPattern: {}, ignoredFields: []}\n\n @src/mongo/db/query/query_planner_test_fixture.cpp:521","extra":"BACKTRACE: {\"backtrace\":[{\"a\":\"7F3468AD12E6\",\"b\":\"7F346851D000\",\"o\":\"5B42E6\",\"s\":\"_ZN5mongo18stack_trace_detail12_GLOBAL__N_122LibunwindStepIte


Generated at Thu Feb 08 05:15:19 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.