Handle PSObject argument specially in method invocation logging by daxian-dbw · Pull Request #18060 · PowerShell/PowerShell

daxian-dbw · Sep 9, 2022

PR Summary

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 · Sep 9, 2022

+                case string:
+                case BigInteger:
+                case var _ when baseType.IsEnum || baseType.IsPrimitive:
+                    return baseObj.ToString();


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

We could take something from our TryFastTrackPrimitiveTypes() method.

Uri value might be worth logging.

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

@iSazonov I cannot find the TryFastTrackPrimitiveTypes method.

@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;

}

Thanks! Added decimal to the list.

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

Use if statement instead of switch because the switch statement generates IL to check "is the instance of this type" for every case branch that matches a type, which is unnecessary. Also, it's easier to arrange the comparison order with if statements.

PaulHigin

LGTM

pull-request-quantifier-deprecated · Sep 9, 2022

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.

adityapatwardhan · Sep 12, 2022

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

ghost · Sep 20, 2022

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

Handy links:

Release Notes

daxian-dbw added 3 commits September 8, 2022 16:00

Handle PSObject argument specially in method invocation logging

9246e55

Minor update

a139e8e

More updates

7574b54

daxian-dbw requested a review from PaulHigin September 9, 2022 00:11

pull-request-quantifier-deprecated Bot added the Extra Small label Sep 9, 2022

ghost assigned TravisEz13 Sep 9, 2022

Update comment

7441f02

daxian-dbw assigned daxian-dbw and unassigned TravisEz13 Sep 9, 2022

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 changed the title ~~String~~ Handle PSObject argument specially in method invocation logging Sep 9, 2022

daxian-dbw commented Sep 9, 2022

View reviewed changes

Comment thread src/System.Management.Automation/engine/runtime/Operations/MiscOps.cs Outdated

daxian-dbw requested a review from SteveL-MSFT September 9, 2022 00:40

daxian-dbw added the Backport-7.3.x-Consider label Sep 9, 2022

iSazonov mentioned this pull request Sep 9, 2022

Make experimental feature PSAMSIMethodInvocationLogging stable #18041

Merged

22 tasks

Avoid 'ToString' as much as possible

f0f2568

daxian-dbw commented Sep 9, 2022

View reviewed changes

PaulHigin approved these changes Sep 9, 2022

View reviewed changes

daxian-dbw added 3 commits September 9, 2022 12:12

Add a few cases

2841314

Add decimal and rearrange order

2bc7ee5

avoid switch statement

90cc450

PaulHigin approved these changes Sep 9, 2022

View reviewed changes

SteveL-MSFT approved these changes Sep 12, 2022

View reviewed changes

daxian-dbw merged commit 3fbd90a into PowerShell:master Sep 12, 2022

daxian-dbw deleted the string branch September 12, 2022 16:15

adityapatwardhan added Backport-7.3.x-Approved and removed Backport-7.3.x-Consider labels Sep 12, 2022

github-actions Bot mentioned this pull request Sep 12, 2022

[release/v7.3.0-rc.1] Handle PSObject argument specially in method invocation logging #18079

Merged

1 task

adityapatwardhan added Backport-7.3.x-Done and removed Backport-7.3.x-Approved labels Sep 13, 2022

ghost mentioned this pull request Sep 20, 2022

PSAMSIMethodInvocationLogging: Stream operation is extremely slow when buffer is created with New-Object #18033

Closed

5 tasks

TravisEz13 mentioned this pull request Sep 30, 2022

Move ApiScan to compliance build #18191

Merged

22 tasks

rhubarb-geek-nz mentioned this pull request May 8, 2024

What programming guidelines are there for PowerShell against the AMSI threat vector? #21536

Closed

daxian-dbw mentioned this pull request Feb 21, 2025

Move .NET method invocation logging to after the needed type conversion is done for method arguments #25022

Merged

	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;
	}

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

Conversation

daxian-dbw commented Sep 9, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

PR Summary

PR Checklist

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

PaulHigin left a comment

Choose a reason for hiding this comment

Uh oh!

pull-request-quantifier-deprecated Bot commented Sep 9, 2022

What can I do to optimize my changes

How to interpret the change counts in git diff output

Uh oh!

adityapatwardhan commented Sep 12, 2022

Uh oh!

ghost commented Sep 20, 2022

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

8 participants

daxian-dbw commented Sep 9, 2022 •

edited

Loading