Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Cleanups for our logging helpers #61669

Merged
merged 6 commits into from
Jun 14, 2022

Conversation

jasonmalinowski
Copy link
Member

@jasonmalinowski jasonmalinowski commented Jun 2, 2022

While looking at our existing logging code to figure out what I can reuse, I noticed a few bits that could use some cleanup. Changes:

  1. Pass around TimeSpans instead of ints for time; this avoids some confusion around units (especially when called "ticks" since that term is ambiguous between different units)
  2. Make the types that are implicitly keyed by something generic, so the type of key is clear.
  3. Rename LogAggregator to CountLogAggregator, so that way the naming matches its sibling types in the type hierarchy.
  4. Move some helpers out of the abstract generic class that don't need to be there.

Commit at a time may or may not help; on one hand each change is pretty mechanical, but the same pieces of code may get touched by multiple commits so that might increase the total amount of code to read pretty significantly.

@@ -116,7 +116,7 @@ protected virtual CompletionItemRules GetCompletionItemRules(ImmutableArray<(ISy

if (completionContext.CompletionOptions.TargetTypedCompletionFilter)
{
var tick = Environment.TickCount;
var stopwatch = SharedStopwatch.StartNew();
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note Environment.TickCount has a precision of around 15ms or so, so switching to Stopwatch here is also going to give a lot more accurate timing.


// Store the request time metrics per LSP method.
_requestDurationLogAggregator.IncreaseCount(methodName, Convert.ToDecimal(ComputeLogValue(requestDuration.TotalMilliseconds)));
_requestDurationLogAggregator.IncreaseCount(methodName, (int)ComputeLogValue(requestDuration.TotalMilliseconds));
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In a follow-up, going to move the logarithmic value code in so it can be shared elsewhere, but leaving it here for now.

@@ -86,9 +92,9 @@ public string GetBucketsAsString()
return pooledStringBuilder.ToStringAndFree();
}

private int GetBucket(decimal value)
private int GetBucket(int value)
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In practice, we were always converting ints to decimals to pass to here, then doing some decimal math only to convert back to an int. This just keeps it simpler.

@jasonmalinowski jasonmalinowski self-assigned this Jun 3, 2022
Comment on lines +45 to +49
/// <summary>
/// The keys in this are either a string or a (string, Guid) tuple. See <see cref="SolutionCrawlerLogger.LogIncrementalAnalyzerProcessorStatistics"/>
/// for what is writing this out.
/// </summary>
private CountLogAggregator<object> _logAggregator = new();
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Refactoring this to be more strongly typed is out of scope for this PR. Until this PR, it wasn't even clear what the types were, so this is at least an improvement!

@@ -24,7 +24,7 @@ internal sealed partial class WorkCoordinator
private readonly Registration _registration;
private readonly object _gate = new();

private readonly LogAggregator _logAggregator = new();
private readonly CountLogAggregator<WorkspaceChangeKind> _logAggregator = new();
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, the WorkCoordinator has two different log aggregators! Until this, it was quite confusing what went in which...

@jasonmalinowski jasonmalinowski marked this pull request as ready for review June 8, 2022 00:18
@jasonmalinowski jasonmalinowski requested a review from a team as a code owner June 8, 2022 00:18
We (mostly) use these to track time, but rather than just letting
them directly take a TimeSpan, we were expecting each of the callers
to distill it down to milliseconds and the pass it as an integer.
This actually clarifies a current surprise that some of our code
calls the data points "ticks" but they're actually logging milliseconds,
but that wasn't obvious since there were just ints being passed around
everywhere.

Even for the cases we were passing around milliseconds, what we were
often doing is taking a TimeSpan, grabbing it's TotalMilliseconds and
then:

- casting it to an int to pass around to our logging functions
- casting that to a decimal to pass to the log aggregators
- doing decimal division to figure out which bucket it goes in
- doing a Math.Floor on that result
- casting that result back to an int

If we just keep everything internally as an int, the division will
already round down and we can avoid all the random extra casting.
Makes it clear this is not a base type of the other ones.
@jasonmalinowski jasonmalinowski merged commit 1c13b39 into dotnet:main Jun 14, 2022
@jasonmalinowski jasonmalinowski deleted the log-aggregator-cleanups branch June 14, 2022 17:58
@ghost ghost added this to the Next milestone Jun 14, 2022
Copy link
Member

@genlu genlu left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is great! Thanks!

chsienki added a commit to chsienki/roslyn that referenced this pull request Jun 21, 2022
…egator-cleanups"

This reverts commit 1c13b39, reversing
changes made to ff8175f.
JoeRobich added a commit that referenced this pull request Jun 24, 2022
Revert "Merge pull request #61669 from jasonmalinowski/log-aggregator…
RikkiGibson added a commit that referenced this pull request Jun 24, 2022
…-cleanups" (#62130)

This reverts commit 1c13b39, reversing
changes made to ff8175f.

Co-authored-by: Chris Sienkiewicz <chsienki@microsoft.com>
Co-authored-by: Joey Robichaud <jorobich@microsoft.com>
@jasonmalinowski jasonmalinowski restored the log-aggregator-cleanups branch June 27, 2022 23:39
@RikkiGibson RikkiGibson modified the milestones: Next, 17.3 P3 Jun 28, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

4 participants