8000 Handle PSObject argument specially in method invocation logging by daxian-dbw · Pull Request #18060 · PowerShell/PowerShell · GitHub
[go: up one dir, main page]
Skip to content

Handle PSObject argument specially in method invocation logging #18060

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.

Sign up for GitHub

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

Jump to bottom
Merged
merged 8 commits into from
Sep 12, 2022
Merged

Handle PSObject argument specially in method invocation logging #18060

merged 8 commits into from
Sep 12, 2022

Conversation

daxian-dbw
Copy link
Member
@daxian-dbw daxian-dbw commented Sep 9, 2022 •
edited
Loading

PR Summary

Fix #18033

The ToString implementation of PSObject does extra work on the base object, for example, unrolling the base object if it's enumerable, which is very expensive.

For method invocation logging, we should avoid calling ToString on a PSObject argument. Instead,

  • If the argument is a pure PSObject, we represent it as "PSObject{}".
  • If the argument is not a PSObject, or is a PSObject wrapping a base object, we represent it as baseObj.ToString().

Here are some log messages with this change:

=== Amsi notification report content ===
<System.IO.File>.Open(<D:\yard\temp\srcFile>, <Open>, <Read>, <Read>)
=== Amsi notification report success: True ===

=== Amsi notification report content ===
<System.IO.File>.Open(<D:\yard\temp\dstFile>, <Create>, <Write>, <Read>)
=== Amsi notification report success: True ===

=== Amsi notification report content ===
<System.IO.FileStream>.Write(<System.Byte[]>, <0>, <1048576>)
=== Amsi notification report success: True ===

=== Amsi notification report content ===
<System.IO.FileStream>.Read(<System.Byte[]>, <0>, <1048576>)
=== Amsi notification report success: True ===

./copytest.ps1 -UseNewObject

Operation   Count Time
---------   ----- ----
Read      1048576 1.23
Write     1048576 0.80
Read      1048576 0.83
Write     1048576 0.79
Read      1048576 0.68
Write     1048576 0.63
Read      1048576 0.57
Write     1048576 0.70
Read      1048576 0.57
Write     1048576 0.58
Read      1048576 0.54
Write     1048576 0.74
Read      1048576 0.56
Write     1048576 0.56
Read      1048576 0.65
Write     1048576 0.70
Read      1048576 0.62
Write     1048576 0.80
Read      1048576 0.73
Write     1048576 0.86
Read            0 0.37
----------
Time Total:  21.6844

PR Checklist

@daxian-dbw daxian-dbw requested a review from PaulHigin September 9, 2022 00:11
@ghost ghost assigned TravisEz13 Sep 9, 2022
@daxian-dbw daxian-dbw assigned daxian-dbw and unassigned TravisEz13 Sep 9, 2022
@daxian-dbw daxian-dbw added the CL-General Indicates that a PR should be marked as a general cmdlet change in the Change Log label Sep 9, 2022
@daxian-dbw daxian-dbw changed the title String Handle PSObject argument specially in method invocation logging Sep 9, 2022
@iSazonov iSazonov mentioned this pull request Sep 9, 2022
Merged
22 tasks
daxian-dbw
daxian-dbw commented Sep 9, 2022
View reviewed changes
src/System.Management.Automation/engine/runtime/Operations/MiscOps.cs Outdated
case string:
case BigInteger:
case var _ when baseType.IsEnum || baseType.IsPrimitive:
return baseObj.ToString();
Copy link
Member Author

Choose a reason for hiding this comment

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

Please review the cases that are covered here, and let me know if any other cases should be added.

Copy link
Collaborator

Choose a reason for hiding this comment

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

We could take something from our TryFastTrackPrimitiveTypes() method.

Copy link

Choose a reason for hiding this comment

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

Uri value might be worth logging.

Copy link
Member Author

Choose a reason for hiding this comment

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

Added Guid, Uri, Version, and SemanticVersion to the list.

@iSazonov I cannot find the TryFastTrackPrimitiveTypes method.

Copy link
Collaborator

Choose a reason for hiding this comment

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

@iSazonov I cannot find the TryFastTrackPrimitiveTypes method.

Ye it's a nested method

PowerShell/src/System.Management.Automation/engine/MshObject.cs

Lines 1260 to 1294 in 397bd87

bool TryFastTrackPrimitiveTypes(object value, out string str)
{
switch (Convert.GetTypeCode(value))
{
case TypeCode.String:
str = (string)value;
break;
case TypeCode.Byte:
case TypeCode.SByte:
case TypeCode.Int16:
case TypeCode.UInt16:
case TypeCode.Int32:
case TypeCode.UInt32:
case TypeCode.Int64:
case TypeCode.UInt64:
case TypeCode.DateTime:
case TypeCode.Decimal:
var formattable = (IFormattable)value;
str = formattable.ToString(format, formatProvider);
break;
case TypeCode.Double:
var dbl = (double)value;
str = dbl.ToString(format ?? LanguagePrimitives.DoublePrecision, formatProvider);
break;
case TypeCode.Single:
var sgl = (float)value;
str = sgl.ToString(format ?? LanguagePrimitives.SinglePrecision, formatProvider);
break;
default:
str = null;
return false;
}
return true;
}

Copy link
Member Author

Choose a reason for hiding this comment

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

Thanks! Added decimal to the list.

Copy link
Member Author

Choose a reason for hiding this comment

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

Also re-arrange the order of the case clauses, based on the likelihood of those types being used as arguments.

Copy link
Member Author

Choose a reason for hiding this comment

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

PaulHigin
PaulHigin approved these changes Sep 9, 2022
View reviewed changes
Copy link
Contributor
@PaulHigin PaulHigin left a comment

Choose a reason for hiding this comment

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

LGTM

@pull-request-quantifier-deprecated
Copy link

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

Quantification details 

Label      : Extra Small
Size       : +18 -1
Percentile : 7.6%

Total files changed: 1

Change summary by file extension:
.cs : +18 -1

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.

@daxian-dbw daxian-dbw merged commit 3fbd90a into PowerShell:master Sep 12, 2022
@daxian-dbw daxian-dbw deleted the string branch September 12, 2022 16:15
@adityapatwardhan
Copy link
Member

/backport to release/v7.3.0-rc.1

@github-actions github-actions bot mentioned this pull request Sep 12, 2022
Merged
1 task
@ghost
Copy link
ghost commented Sep 20, 2022

🎉v7.3.0-preview.8 has been released which incorporates this pull request.:tada:

Handy links:

@ghost ghost mentioned this pull request Sep 20, 2022
Closed
5 tasks
@TravisEz13 TravisEz13 mentioned this pull request Sep 30, 2022
Merged
22 tasks
@rhubarb-geek-nz rhubarb-geek-nz mentioned this pull request May 8, 2024
Closed
@daxian-dbw daxian-dbw mentioned this pull request Feb 21, 2025
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@hazychill hazychill hazychill left review comments

@iSazonov iSazonov iSazonov left review comments

@SeeminglyScience SeeminglyScience SeeminglyScience left review comments

@SteveL-MSFT SteveL-MSFT SteveL-MSFT approved these changes

@PaulHigin PaulHigin PaulHigin approved these changes

Assignees

@daxian-dbw daxian-dbw

Labels
Backport-7.3.x-Done CL-General Indicates that a PR should be marked as a general cmdlet change in the Change Log Extra Small
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

PSAMSIMethodInvocationLogging: Stream operation is extremely slow when buffer is created with New-Object
8 participants
@daxian-dbw @adityapatwardhan @hazychill @SteveL-MSFT @PaulHigin @iSazonov @SeeminglyScience @TravisEz13
0