Skip to content

Navigation Menu

Sign in
Appearance settings

Search code, repositories, users, issues, pull requests...

Provide feedback

We read every piece of feedback, and take your input very seriously.

Saved searches

Use saved searches to filter your results more quickly

Appearance settings

Conversation

@iSazonov
Copy link
Collaborator

@iSazonov iSazonov commented Oct 10, 2022

PR Summary

Significant refactoring PSTraceSource class.

Rationale:

The original code causes significant resource consumption even when tracing is turned off.
Part of the problem was reduced earlier by creating many helper methods. This reduced the allocations when tracing is turned off noticeably, but did not eliminate them all (scope tracing, early argument evaluations).
These problems also limited developers, forcing them to use simple strings instead of displaying really useful information.

Benefits gained:

  1. New C# feature - interpolated string handler - allow us to optimize PSTraceSource code:
    • exclude boxing and related allocations
    • reduce cascade allocations
  2. Implemented one universal PSTraceWrite() method:
    • the method should be used for most types of tracing defined by PSTraceSourceOptions enum.
    • all old helper methods (that made a huge number of allocations) were removed. The file size has decreased by 1000 lines, almost twice as much.
    • the method benefits from interpolated string handler that allows to exclude argument boxing and lazily evaluate arguments.
  3. Implemented one universal ref readonly struct PSTraceScope for scope tracing.
    • the struct is disposable that allows automatically write one message on scope begin and one message on scope end.
    • the struct exclude allocations at trace enabled time.
    • the struct benefits from interpolated string handler that allows to exclude argument boxing and lazily evaluate arguments.
  4. PSTraceSource class was updated with nullable annotations.
  5. All call sites were updated with new code - PSTraceWrite() method and PSTraceScope struct.

Reviewers can use debugger and the follow command:

Trace-Command -PSHost -Name FileSystemProvider -Expression {Get-Item c:\}

PR Context

History #10052.

From #10052 (review)

I will look into the FormatOutputLine later in a separate PR.

@daxian-dbw The time has come! 😄

PR Checklist

@iSazonov iSazonov added the CL-Performance Indicates that a PR should be marked as a performance improvement in the Change Log label Oct 10, 2022
@iSazonov iSazonov requested a review from anmenaga as a code owner October 10, 2022 13:08
@ghost ghost added the Waiting on Author The PR was reviewed and requires changes or comments from the author before being accept label Oct 10, 2022
@daxian-dbw
Copy link
Member

This is great! There are more places to apply this, like all the WriteVerbose and WriteWarning calls in engine. This will save a great deal of string allocations.

@iSazonov
Copy link
Collaborator Author

This is great! There are more places to apply this, like all the WriteVerbose and WriteWarning calls in engine. This will save a great deal of string allocations.

I suggest doing this in some follow PRs because we need to change dozens of files, which will make it difficult to review this PR.

@ghost ghost removed the Waiting on Author The PR was reviewed and requires changes or comments from the author before being accept label Oct 25, 2022
@ghost ghost added the Waiting on Author The PR was reviewed and requires changes or comments from the author before being accept label Oct 25, 2022
@daxian-dbw
Copy link
Member

Leveraging the interpolated string handler for WriteLine doesn't further reduce allocations for the common cases where tracing is disabled, because your previous PR #10052 already eliminated allocation (mostly) for WriteLine when tracing is disabled.

The current change in this PR will reduce more allocations when tracing is enabled, but that's not a common scenario and thus not very interesting (reducing allocation is always good, it's just not as important in this case).

Back to the design of the current change, it would require one handler implementation per every logging option, because the handler has built-in assumption of the tracing option to check against. This is obviously not desired. What we want is a single handler implementation that can work for all logging options. To achieve this goal, we need to first do significant refactoring to the existing PSTraceSource methods -- changing method like TraceWarning(xxx), WriteLine(xxx) and etc. to Trace(Option option, xxxx) -- so that each method doesn't have built-in assumption but instead the passed-in option instructs what to do with this tracing operation. However, the refactoring work will be massive.

@iSazonov
Copy link
Collaborator Author

iSazonov commented Nov 8, 2022

Leveraging the interpolated string handler for WriteLine doesn't further reduce allocations for the common cases where tracing is disabled, because your previous PR #10052 already eliminated allocation (mostly) for WriteLine when tracing is disabled.

We still do early evaluating of arguments (there is even StringBuilder!). We have reduced boxing with a lot of helpers, but now we can remove them and use a single method, which is much easier and clearer.
When tracing is disabled we reduce allocations even more significantly.
All this already makes this change very useful.

However, the refactoring work will be massive.

I am trying to keep the PR as small as possible.
My plan:

  1. Merge the PR
  2. Remove all WriteLine() helpers and replace with new one in follow PR
  3. Think whether we want to continue and refactor other trace helpers.
    They are so rarely used that I thought it might not be necessary. But we can unify all methods with one Trace(Option option, xxxx) in the next PR if you want.

@ghost ghost removed the Waiting on Author The PR was reviewed and requires changes or comments from the author before being accept label Nov 8, 2022
@daxian-dbw
Copy link
Member

daxian-dbw commented Nov 14, 2022

When tracing is disabled, we reduce allocations even more significantly.
All this already makes this change very useful.

Can you please point me to some examples to prove the bold part?

Also, back to the design of the current change, I have concern about having one handler implementation per every logging option. See the 3rd paragraph in my comment #18246 (comment) for details.


When tracing is disabled, we ideally should never call to the WriteLine methods. That's doable for the parameter binders but may be harder for the uses in some other places.

@iSazonov
Copy link
Collaborator Author

When tracing is disabled, we reduce allocations even more significantly.
All this already makes this change very useful.

Can you please point me to some examples to prove the bold part?

You can look how WriteLine(string format, object arg1) is used (384 times). Most is strings but there are FileInfo, Uri, StringBuilder, ...

Also, back to the design of the current change, I have concern about having one handler implementation per every logging option. See the 3rd paragraph in my comment #18246 (comment) for details.

Options:

  1. Most benefits we get from WriteLine() refactoring. Rest of trace methods we could ignore.
  2. Create some handlers since they are very simple.
  3. I'd prefer to convert all methods to Trace(Option option, xxxx) and use one handler.

@ghost ghost added the Review - Needed The PR is being reviewed label Nov 22, 2022
@ghost
Copy link

ghost commented Nov 22, 2022

This pull request has been automatically marked as Review Needed because it has been there has not been any activity for 7 days.
Maintainer, please provide feedback and/or mark it as Waiting on Author

@daxian-dbw
Copy link
Member

You can look how WriteLine(string format, object arg1) is used (384 times). Most is strings but there are FileInfo, Uri, StringBuilder, ...

Having FileInfo, Uri, StringBuilder passed in to arg1 in this case doesn't cause any allocation when the tracing is disabled, so it's still not clear to me where the big saving would be from.

I'd prefer to convert all methods to Trace(Option option, xxxx) and use one handler.

This would be most ideal -- being consistent and modern. That will also allow the pattern to be easily copied in other places. The problem is that the saving in allocation will not be obvious when the tracing is disabled (this is the common scenario), which will make the value/cost of this work less attractive :(

@ghost ghost removed the Review - Needed The PR is being reviewed label Nov 28, 2022
@daxian-dbw
Copy link
Member

Again, I think when tracing is disabled, we ideally should never call to the WriteLine methods. That's doable for the parameter binders but may be harder for the uses in some other places.

@daxian-dbw daxian-dbw added the Waiting on Author The PR was reviewed and requires changes or comments from the author before being accept label Nov 28, 2022
@iSazonov
Copy link
Collaborator Author

Again, I think when tracing is disabled, we ideally should never call to the WriteLine methods. That's doable for the parameter binders but may be harder for the uses in some other places.

Can you clarify how we could achieve this?
Since it is in run time we should check if (_flags.HasFlag(PSTraceSourceOptions.WriteLine)) in every callsite. Do you say we need to move the check out of WriteLine method?

Having FileInfo, Uri, StringBuilder passed in to arg1 in this case doesn't cause any allocation when the tracing is disabled, so it's still not clear to me where the big saving would be from.

We seem to be in slightly different contexts. :-) I must have made a bad initial description.
Earlier we added many helper methods to remove unnecessary allocations. It was a workaround that didn't eliminate the allocation problem completely.

Now we can remove all these helper methods and use a single method that completely solves the problem. There are still limitations there, but they are not critical since the API is not public.

I'd prefer to convert all methods to Trace(Option option, xxxx) and use one handler.

This would be most ideal -- being consistent and modern. That will also allow the pattern to be easily copied in other places.

We still can keep using specific names like WriteLine and have one handler. For this we should have one more optional parameter in the handler and in the methods. What is pattern from the two ones you like more?

The problem is that the saving in allocation will not be obvious when the tracing is disabled (this is the common scenario), which will make the value/cost of this work less attractive :(

The benefit is that the new pattern eliminates allocations and errors like s_tracer.WriteLine("DSC ClassCache: loading file '{0}' added the following classes to the cache: {1}", path, sb.ToString());.

@ghost ghost removed the Waiting on Author The PR was reviewed and requires changes or comments from the author before being accept label Nov 29, 2022
@ghost ghost added the Review - Needed The PR is being reviewed label Dec 6, 2022
@ghost
Copy link

ghost commented Dec 6, 2022

This pull request has been automatically marked as Review Needed because it has been there has not been any activity for 7 days.
Maintainer, please provide feedback and/or mark it as Waiting on Author

@pull-request-quantifier-deprecated

This PR has 3098 quantified lines of changes. In general, a change size of upto 200 lines is ideal for the best PR experience!


Quantification details

Label      : Extra Large
Size       : +1243 -1855
Percentile : 100%

Total files changed: 67

Change summary by file extension:
.cs : +1242 -1855
.ps1 : +1 -0

Change counts above are quantified counts, based on the PullRequestQuantifier customizations.

Why proper sizing of changes matters

Optimal pull request sizes drive a better predictable PR flow as they strike a
balance between between PR complexity and PR review overhead. PRs within the
optimal size (typical small, or medium sized PRs) mean:

  • Fast and predictable releases to production:
    • Optimal size changes are more likely to be reviewed faster with fewer
      iterations.
    • Similarity in low PR complexity drives similar review times.
  • Review quality is likely higher as complexity is lower:
    • Bugs are more likely to be detected.
    • Code inconsistencies are more likely to be detected.
  • Knowledge sharing is improved within the participants:
    • Small portions can be assimilated better.
  • Better engineering practices are exercised:
    • Solving big problems by dividing them in well contained, smaller problems.
    • Exercising separation of concerns within the code changes.

What can I do to optimize my changes

  • Use the PullRequestQuantifier to quantify your PR accurately
    • Create a context profile for your repo using the context generator
    • Exclude files that are not necessary to be reviewed or do not increase the review complexity. Example: Autogenerated code, docs, project IDE setting files, binaries, etc. Check out the Excluded section from your prquantifier.yaml context profile.
    • Understand your typical change complexity, drive towards the desired complexity by adjusting the label mapping in your prquantifier.yaml context profile.
    • Only use the labels that matter to you, see context specification to customize your prquantifier.yaml context profile.
  • Change your engineering behaviors
    • For PRs that fall outside of the desired spectrum, review the details and check if:
      • Your PR could be split in smaller, self-contained PRs instead
      • Your PR only solves one particular issue. (For example, don't refactor and code new features in the same PR).

How to interpret the change counts in git diff output

  • One line was added: +1 -0
  • One line was deleted: +0 -1
  • One line was modified: +1 -1 (git diff doesn't know about modified, it will
    interpret that line like one addition plus one deletion)
  • Change percentiles: Change characteristics (addition, deletion, modification)
    of this PR in relation to all other PRs within the repository.


Was this comment helpful? 👍  :ok_hand:  :thumbsdown: (Email)
Customize PullRequestQuantifier for this repository.

@iSazonov iSazonov closed this Apr 23, 2023
@ghost ghost removed the Review - Needed The PR is being reviewed label Apr 23, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

CL-Performance Indicates that a PR should be marked as a performance improvement in the Change Log Extra Large

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants

Morty Proxy This is a proxified and sanitized view of the page, visit original site.