[SERVER-54723] Shorten resmoke log prefixes Created: 30/Jul/20 Updated: 29/Oct/23 Resolved: 05/Mar/21 |
|
| Status: | Closed |
| Project: | Core Server |
| Component/s: | Testing Infrastructure |
| Affects Version/s: | None |
| Fix Version/s: | 4.9.0 |
| Type: | Bug | Priority: | Major - P3 |
| Reporter: | Daniel Gottlieb (Inactive) | Assignee: | Mikhail Shchatko |
| Resolution: | Fixed | Votes: | 0 |
| Labels: | tig-qwin-eligible, tig-resmoke | ||
| Remaining Estimate: | Not Specified | ||
| Time Spent: | Not Specified | ||
| Original Estimate: | Not Specified | ||
| Issue Links: |
|
||||||||||||||||||||||||||||
| Backwards Compatibility: | Fully Compatible | ||||||||||||||||||||||||||||
| Operating System: | ALL | ||||||||||||||||||||||||||||
| Sprint: | STM 2021-03-08, STM 2021-03-22 | ||||||||||||||||||||||||||||
| Participants: | |||||||||||||||||||||||||||||
| Story Points: | 2 | ||||||||||||||||||||||||||||
| Description |
|
Log lines (particularly when run through resmoke) have been and are getting longer. The new information we want to add is useful (e.g: The current log lines outputs the following information (as an example, not all log lines are the same):
One workflow I have when debugging a failure in the server (as opposed to an unexpected response):
Information like the job and loggers are necessary for filtering, but not looking at. The fixture name and log level are always irrelevant to me. The thread name, log message and at times, the timestamp (more for temporal locality or cross referencing) are most important. Node identification is sometimes only needed for filtering, and sometimes needed because I need to look at messages from multiple nodes simultaneously. Lobster coloring is often a sufficient for distinguishing between nodes in this case. Common refrains in execution standups when going over new BFs that have come in (where the BB has already done an excellent job picking out the relevant log lines) are: "Scroll to the right [please]" and "keep going..." |
| Comments |
| Comment by Githook User [ 04/Mar/21 ] | |||||||||||||||
|
Author: {'name': 'Mikhail Shchatko', 'email': 'mikhail.shchatko@mongodb.com', 'username': 'MikhailShchatko'}Message: | |||||||||||||||
| Comment by Robert Guo (Inactive) [ 03/Mar/21 ] | |||||||||||||||
|
Got it david.bradford, I'll set something up. | |||||||||||||||
| Comment by David Bradford (Inactive) [ 03/Mar/21 ] | |||||||||||||||
|
Would be possible for someone to sync up with me before this gets merged? This will likely break the log parsing that we do for BFGs and BF suggestions. | |||||||||||||||
| Comment by Mikhail Shchatko [ 26/Feb/21 ] | |||||||||||||||
|
After having conversation in slack with daniel.gottlieb and robert.guo we decided to do the following changes:
old
new
| |||||||||||||||
| Comment by Robert Guo (Inactive) [ 06/Oct/20 ] | |||||||||||||||
|
Nope. We're going to try to get to it in our next quick wins bucket. | |||||||||||||||
| Comment by Brooke Miller [ 22/Sep/20 ] | |||||||||||||||
|
Is this still waiting for user input, robert.guo? | |||||||||||||||
| Comment by Robert Guo (Inactive) [ 04/Aug/20 ] | |||||||||||||||
|
Try to do as much as we can in resmoke and not touch the Server for this ticket. 1. update timestamp format, 2. shortening static prefixes, reduce spacings. | |||||||||||||||
| Comment by Brooke Miller [ 04/Aug/20 ] | |||||||||||||||
|
robert.guo to do the initial investigation with stakeholders about their preference. | |||||||||||||||
| Comment by Brooke Miller [ 04/Aug/20 ] | |||||||||||||||
|
In Triaging, we agreed that the last suggestion is the best route for implementation. However, we should modify the timestamp format to include colons. Before we go ahead and implement this, we should get this in front of stakeholders to make sure the majority would be OK with this change. | |||||||||||||||
| Comment by Ryan Timmons [ 30/Jul/20 ] | |||||||||||||||
|
Strategies I've used very successfully in the past:
Becomes:
This cuts 84 chars of prefix down to 58 while still being, imho, just as mentally obvious when reading it. And we've not made it any less machine-parsable either. Some would go a step further and say the date info isn't useful, separators aren't needed, and Zulu can be implied:
This veers away from any sort of ISO-8601 format but it saves another 13 characters of what is noise in nearly all cases. At any rate it seems reasonable to establish a stable regex so that lobster and other tooling can reliably expand or hide the data the user doesn't care about. In projects I've worked on in the past we've had a published PCRE that describes log-lines and we "required" all projects that parsed logs make reference to the file so we could easily find all the places that used the regex whenever we needed to change it. This saved us a production outage when we switched from offsets (+000) to Zulu, so it paid off. |