Improve recently added log messages by adding context to indicate which build is relevant #640
Conversation
…ch build is relevant Also remove redundant class and method names from log messages and make some internal methods package-private instead of public.
| @@ -269,7 +268,7 @@ public static float clampDuration(float d) { | |||
| return Math.min(365.0f * 24 * 60 * 60, Math.max(0.0f, d)); | |||
| } | |||
|
|
|||
| public static CaseResult parse(SuiteResult parent, final XMLStreamReader reader, String ver) | |||
There was a problem hiding this comment.
As far as I know nothing should be using these new methods from #625, so I made them all package-private, but if that is not true, let me know and I will revert that part of the change.
| if (LOGGER.isLoggable(Level.FINEST)) { | ||
| LOGGER.finest("CaseResult.parse encountered an unknown field: " + elementName); | ||
| } | ||
| LOGGER.finest(() -> "Unknown field in " + context + ": " + elementName); |
There was a problem hiding this comment.
I also checked whether XMLReader.getLocation included a file name to avoid having to pass context everywhere, but getPublicID and getSystemID just return null (and IDK what they would even return if they weren't null). We could add line and column numbers to give even more context, but I don't really think it would be helpful in practice.
| @@ -179,8 +179,8 @@ public synchronized TestResult getResult() { | |||
| skipCount = r.getSkipCount(); | |||
| } | |||
| long d = System.nanoTime() - started; | |||
| if (d > 500000000L && LOGGER.isLoggable(Level.WARNING)) { | |||
There was a problem hiding this comment.
500000000 is 5e8, or 0.5 seconds. I adjusted the code to use TimeUnit to make it clearer, but I could switch it to 500 * 1000 * 1000 or whatever you think is clearest.
There was a problem hiding this comment.
(I also wonder if this threshold is too low for WARNING and it should be increased to 1-2 seconds, maybe logging at FINE for stuff between 0.5-1 seconds)
There was a problem hiding this comment.
I like the idea of setting the threshold higher for logging at less than 2 seconds, but approve this pull request with or without that change.
| @@ -69,7 +70,6 @@ | |||
| @SuppressFBWarnings(value = "UG_SYNC_SET_UNSYNC_GET", justification = "False positive") | |||
| public class TestResultAction extends AbstractTestResultAction<TestResultAction> | |||
| implements StaplerProxy, SimpleBuildStep.LastBuildAction { | |||
| private static final Logger LOGGER = Logger.getLogger(TestResultAction.class.getName()); | |||
There was a problem hiding this comment.
This was added in #625, but we already had a logger at the bottom of the file, it was just named lowercase logger.
| @@ -179,8 +179,8 @@ public synchronized TestResult getResult() { | |||
| skipCount = r.getSkipCount(); | |||
| } | |||
| long d = System.nanoTime() - started; | |||
| if (d > 500000000L && LOGGER.isLoggable(Level.WARNING)) { | |||
There was a problem hiding this comment.
I like the idea of setting the threshold higher for logging at less than 2 seconds, but approve this pull request with or without that change.
|
@dwnusbaum Thanks! |
Amends #625. @olamy recently saw a bunch of these log messages, which were added in that PR I guess to help detect slow loading, but they are not really useful without indicating which build is relevant:
This PR does 3 main things:
Run.toString()orFile.toString()to the message to provide contextClass.methodparts of the messages, which are added automatically by the default Jenkins loggerparsemethods in Test history refactoring and improvements #625 that as far as I understand were only intended for internal use frompublicto package-private. This plugin is a dependency of various other plugns, so I think it is desirable to avoid accidentally increasing the API surfaceTesting done
I mangled some test files locally and enabled FINEST logging to check that log messages worked and indicated which build was relevant.
Submitter checklist