From b041aa8fa90d4892d1e18d5cf4d3614147727129 Mon Sep 17 00:00:00 2001 From: Jordan Borean Date: Fri, 8 Mar 2024 11:52:32 +1000 Subject: [PATCH] Add MethodInvocation trace for overload tracing Adds a new trace source called MethodInvocation which can be used to trace what .NET methods PowerShell invokes. This is useful for both seeing what .NET methods the code is calling but also for seeing what overload PowerShell has selected based on the arguments provided. This only applies to .NET methods, ETS members are not covered by this trace source but could potentially be added in the future. --- .../engine/parser/Compiler.cs | 3 + .../engine/runtime/Binding/Binders.cs | 18 ++ .../Trace-Command.Tests.ps1 | 166 ++++++++++++++++++ 3 files changed, 187 insertions(+) diff --git a/src/System.Management.Automation/engine/parser/Compiler.cs b/src/System.Management.Automation/engine/parser/Compiler.cs index c9cc5a3f6d..fddd651cc7 100644 --- a/src/System.Management.Automation/engine/parser/Compiler.cs +++ b/src/System.Management.Automation/engine/parser/Compiler.cs @@ -474,6 +474,9 @@ internal static class CachedReflectionInfo internal static readonly MethodInfo PSSetMemberBinder_SetAdaptedValue = typeof(PSSetMemberBinder).GetMethod(nameof(PSSetMemberBinder.SetAdaptedValue), StaticFlags); + internal static readonly MethodInfo PSTraceSource_WriteLine = + typeof(PSTraceSource).GetMethod(nameof(PSTraceSource.WriteLine), InstanceFlags, new[] { typeof(string), typeof(object) }); + internal static readonly MethodInfo PSVariableAssignmentBinder_CopyInstanceMembersOfValueType = typeof(PSVariableAssignmentBinder).GetMethod(nameof(PSVariableAssignmentBinder.CopyInstanceMembersOfValueType), StaticFlags); diff --git a/src/System.Management.Automation/engine/runtime/Binding/Binders.cs b/src/System.Management.Automation/engine/runtime/Binding/Binders.cs index 3e3ec3fbca..0bb6bb5173 100644 --- a/src/System.Management.Automation/engine/runtime/Binding/Binders.cs +++ b/src/System.Management.Automation/engine/runtime/Binding/Binders.cs @@ -6525,6 +6525,13 @@ public override DynamicMetaObject FallbackInvoke(DynamicMetaObject target, Dynam internal sealed class PSInvokeMemberBinder : InvokeMemberBinder { + [TraceSource("MethodInvocation", "Traces the invocation of .NET methods.")] + internal static readonly PSTraceSource MethodInvocationTracer = + PSTraceSource.GetTracer( + "MethodInvocation", + "Traces the invocation of .NET methods.", + false); + internal enum MethodInvocationType { Ordinary, @@ -6935,6 +6942,17 @@ public override DynamicMetaObject FallbackInvokeMember(DynamicMetaObject target, expr = Expression.Block(expr, ExpressionCache.AutomationNullConstant); } + if (MethodInvocationTracer.IsEnabled) + { + expr = Expression.Block( + Expression.Call( + Expression.Constant(MethodInvocationTracer), + CachedReflectionInfo.PSTraceSource_WriteLine, + Expression.Constant("Invoking method: {0}"), + Expression.Constant(result.methodDefinition)), + expr); + } + // Expression block runs two expressions in order: // - Log method invocation to AMSI Notifications (can throw PSSecurityException) // - Invoke method diff --git a/test/powershell/Modules/Microsoft.PowerShell.Utility/Trace-Command.Tests.ps1 b/test/powershell/Modules/Microsoft.PowerShell.Utility/Trace-Command.Tests.ps1 index cdccd0e9ed..60ddac4b82 100644 --- a/test/powershell/Modules/Microsoft.PowerShell.Utility/Trace-Command.Tests.ps1 +++ b/test/powershell/Modules/Microsoft.PowerShell.Utility/Trace-Command.Tests.ps1 @@ -84,6 +84,172 @@ Describe "Trace-Command" -tags "CI" { } } + Context "MethodInvocation traces" { + + BeforeAll { + $filePath = Join-Path $TestDrive 'testtracefile.txt' + + class MyClass { + MyClass() {} + MyClass([int]$arg) {} + + [void]Method() { return } + [void]Method([string]$arg) { return } + [void]Method([int]$arg) { return } + + [string]ReturnMethod() { return "foo" } + + static [void]StaticMethod() { return } + static [void]StaticMethod([string]$arg) { return } + } + + # C# classes support more features than pwsh classes + Add-Type -TypeDefinition @' +namespace TraceCommandTests; + +public sealed class OverloadTests +{ + public int PropertySetter { get; set; } + + public OverloadTests() {} + public OverloadTests(int value) + { + PropertySetter = value; + } + + public void GenericMethod() + {} + + public T GenericMethodWithArg(T obj) => obj; + + public void MethodWithDefault(string arg1, int optional = 1) + {} + + public void MethodWithOut(out int val) + { + val = 1; + } + + public void MethodWithRef(ref int val) + { + val = 1; + } +} +'@ + } + + AfterEach { + Remove-Item $filePath -Force -ErrorAction SilentlyContinue + } + + It "Traces instance method" { + $myClass = [MyClass]::new() + Trace-Command -Name MethodInvocation -Expression { + $myClass.Method(1) + } -FilePath $filePath + Get-Content $filePath | Should -BeLike "*Invoking method: void Method(int arg)" + } + + It "Traces static method" { + Trace-Command -Name MethodInvocation -Expression { + [MyClass]::StaticMethod(1) + } -FilePath $filePath + Get-Content $filePath | Should -BeLike "*Invoking method: static void StaticMethod(string arg)" + } + + It "Traces method with return type" { + $myClass = [MyClass]::new() + Trace-Command -Name MethodInvocation -Expression { + $myClass.ReturnMethod() + } -FilePath $filePath + Get-Content $filePath | Should -BeLike "*Invoking method: string ReturnMethod()" + } + + It "Traces constructor" { + Trace-Command -Name MethodInvocation -Expression { + [TraceCommandTests.OverloadTests]::new("1234") + } -FilePath $filePath + Get-Content $filePath | Should -BeLike "*Invoking method: TraceCommandTests.OverloadTests new(int value)" + } + + It "Traces Property setter invoked as a method" { + $obj = [TraceCommandTests.OverloadTests]::new() + Trace-Command -Name MethodInvocation -Expression { + $obj.set_PropertySetter(1234) + } -FilePath $filePath + Get-Content $filePath | Should -BeLike "*Invoking method: void set_PropertySetter(int value)" + } + + It "Traces generic method" { + $obj = [TraceCommandTests.OverloadTests]::new() + Trace-Command -Name MethodInvocation -Expression { + $obj.GenericMethod[int]() + } -FilePath $filePath + # FUTURE: The underlying mechanism should be improved here + Get-Content $filePath | Should -BeLike "*Invoking method: void GenericMethod()" + } + + It "Traces generic method with argument" { + $obj = [TraceCommandTests.OverloadTests]::new() + Trace-Command -Name MethodInvocation -Expression { + $obj.GenericMethodWithArg("foo") + } -FilePath $filePath + Get-Content $filePath | Should -BeLike "*Invoking method: string GenericMethodWithArg(string obj)" + } + + It "Traces .NET call with default value" { + $obj = [TraceCommandTests.OverloadTests]::new() + Trace-Command -Name MethodInvocation -Expression { + $obj.MethodWithDefault("foo") + } -FilePath $filePath + Get-Content $filePath | Should -BeLike "*Invoking method: void MethodWithDefault(string arg1, int optional = 1)" + } + + It "Traces method with ref argument" { + $obj = [TraceCommandTests.OverloadTests]::new() + $v = 1 + + Trace-Command -Name MethodInvocation -Expression { + $obj.MethodWithRef([ref]$v) + } -FilePath $filePath + # [ref] goes through the binder so will trigger the first trace + Get-Content $filePath | Select-Object -Skip 1 | Should -BeLike "*Invoking method: void MethodWithRef(``[ref``] int val)" + } + + It "Traces method with out argument" { + $obj = [TraceCommandTests.OverloadTests]::new() + $v = 1 + + Trace-Command -Name MethodInvocation -Expression { + $obj.MethodWithOut([ref]$v) + } -FilePath $filePath + # [ref] goes through the binder so will trigger the first trace + Get-Content $filePath | Select-Object -Skip 1 | Should -BeLike "*Invoking method: void MethodWithOut(``[ref``] int val)" + } + + It "Traces a binding error" { + Trace-Command -Name MethodInvocation -Expression { + # try/catch is used as error formatter will hit the trace as well + try { + [System.Runtime.InteropServices.Marshal]::SizeOf([int]) + } + catch { + # Satisfy codefactor + $_ | Out-Null + } + } -FilePath $filePath + # type fqn is used, the wildcard avoids hardcoding that + Get-Content $filePath | Should -BeLike "*Invoking method: static int SizeOf(System.RuntimeType, * structure)" + } + + It "Traces LINQ call" { + Trace-Command -Name MethodInvocation -Expression { + [System.Linq.Enumerable]::Union([int[]]@(1, 2), [int[]]@(3, 4)) + } -FilePath $filePath + Get-Content $filePath | Should -BeLike "*Invoking method: static System.Collections.Generic.IEnumerable``[int``] Union(System.Collections.Generic.IEnumerable``[int``] first, System.Collections.Generic.IEnumerable``[int``] second)" + } + } + Context "Trace-Command tests for code coverage" { BeforeAll {