From 324a2842f6395acb501b99b9d4ae21e328500d1a Mon Sep 17 00:00:00 2001 From: Travis Plunk Date: Mon, 20 Aug 2018 12:47:24 -0700 Subject: [PATCH 1/5] log null character in a scriptblock as `\u2400` --- .../engine/runtime/CompiledScriptBlock.cs | 13 +++++++++++++ 1 file changed, 13 insertions(+) diff --git a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs index d19dca4c517..343f5fbb054 100644 --- a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs +++ b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs @@ -1317,6 +1317,7 @@ private static bool WriteScriptBlockToLog(ScriptBlock scriptBlock, int segment, // See if we need to encrypt the event log message. This info is all cached by Utils.GetPolicySetting(), // so we're not hitting the configuration file for every script block we compile. ProtectedEventLogging logSetting = Utils.GetPolicySetting(Utils.SystemWideOnlyConfig); + bool wasEncoded = false; if (logSetting != null) { lock (s_syncObject) @@ -1334,6 +1335,7 @@ private static bool WriteScriptBlockToLog(ScriptBlock scriptBlock, int segment, // version. if (s_encryptionRecipients != null) { + // Encrypt the raw Text from the scriptblock. The user may have to deal with any control characters in the data. ExecutionContext executionContext = LocalPipeline.GetExecutionContextFromTLS(); ErrorRecord error = null; byte[] contentBytes = System.Text.Encoding.UTF8.GetBytes(textToLog); @@ -1355,11 +1357,22 @@ private static bool WriteScriptBlockToLog(ScriptBlock scriptBlock, int segment, else { textToLog = encodedContent; + wasEncoded = true; } } } } + if(!wasEncoded) + { + // The logging mechanism(s) cannot handle null and rendering may not be able to handle + // null as we have the string defined as a null terminated string in the manifest. + // So, replace null characters with the Unicode `SYMBOL FOR NULL` + // We don't just remove the characters to preserve the fact that a null character was there. + + textToLog = textToLog.Replace('\u0000','\u2400'); + } + if (scriptBlock._scriptBlockData.HasSuspiciousContent) { PSEtwLog.LogOperationalWarning(PSEventId.ScriptBlock_Compile_Detail, PSOpcode.Create, PSTask.ExecuteCommand, PSKeyword.UseAlwaysOperational, From f06f0ec47a09339650e641dcd2d534450c5c7e4a Mon Sep 17 00:00:00 2001 From: Travis Plunk Date: Mon, 20 Aug 2018 19:04:15 -0700 Subject: [PATCH 2/5] Add test for scriptblock logging on mac with null character --- test/powershell/Host/Logging.Tests.ps1 | 38 ++++++++++++++++++++++++++ 1 file changed, 38 insertions(+) diff --git a/test/powershell/Host/Logging.Tests.ps1 b/test/powershell/Host/Logging.Tests.ps1 index 98e7d23d97e..a4aafd7be83 100644 --- a/test/powershell/Host/Logging.Tests.ps1 +++ b/test/powershell/Host/Logging.Tests.ps1 @@ -342,6 +342,44 @@ $pid } } + It 'Verifies scriptblock logging with null character' -Skip:(!$IsSupportedEnvironment) { + try { + $script = @' +$pid +& ([scriptblock]::create("Write-Verbose 'testheader123$([char]0x0000)' ;Write-verbose 'after'")) +'@ + $configFile = WriteLogSettings -ScriptBlockLogging -LogId $logId -LogLevel Verbose + $testFileName = 'test01.ps1' + $testScriptPath = Join-Path -Path $TestDrive -ChildPath $testFileName + $script | Out-File -FilePath $testScriptPath -Force + $testPid = & $powershell -NoProfile -SettingsFile $configFile -Command $testScriptPath + + Export-PSOsLog -After $after -LogPid $testPid -TimeoutInMilliseconds 30000 -IntervalInMilliseconds 3000 -MinimumCount 18 | + Set-Content -Path $contentFile + $items = @(Get-PSOsLog -Path $contentFile -Id $logId -After $after -Verbose) + + $items | Should -Not -Be $null + $items.Count | Should -BeGreaterThan 2 + $createdEvents = $items | where-object {$_.EventId -eq 'ScriptBlock_Compile_Detail:ExecuteCommand.Create.Verbose'} + $createdEvents.Count | should -BeGreaterOrEqual 3 + + # Verify we log that we are executing a file + $createdEvents[0].Message | Should -Match ($scriptBlockCreatedRegExTemplate -f ".*/$testFileName") + + # Verify we log that we are the script to create the scriptblock + $createdEvents[1].Message | Should -Match ($scriptBlockCreatedRegExTemplate -f (Get-RegEx -SimpleMatch $Script)) + + # Verify we log that we are excuting the created scriptblock + $createdEvents[2].Message | Should -Match ($scriptBlockCreatedRegExTemplate -f "Write\-Verbose 'testheader123␀' ;Write\-verbose 'after'") + } + catch { + if (Test-Path $contentFile) { + Send-VstsLogFile -Path $contentFile + } + throw + } + } + # This is pending because it results in false postitives (-Skip:(!$IsSupportedEnvironment) ) It 'Verifies logging level filtering works' -Pending { try { From ec12b154fa54fdbb3ffafd0f8f538e81b8ea9c97 Mon Sep 17 00:00:00 2001 From: Travis Plunk Date: Wed, 22 Aug 2018 10:28:10 -0700 Subject: [PATCH 3/5] add test for scriptblock logging with null character on Linux --- test/powershell/Host/Logging.Tests.ps1 | 29 ++++++++++++++++++++++++++ 1 file changed, 29 insertions(+) diff --git a/test/powershell/Host/Logging.Tests.ps1 b/test/powershell/Host/Logging.Tests.ps1 index a4aafd7be83..5cd54ddcc1d 100644 --- a/test/powershell/Host/Logging.Tests.ps1 +++ b/test/powershell/Host/Logging.Tests.ps1 @@ -216,6 +216,35 @@ $pid $createdEvents[2].Message | Should -Match ($scriptBlockCreatedRegExTemplate -f "Write\-Verbose 'testheader123' ;Write\-verbose 'after'") } + It 'Verifies scriptblock logging with null character' -Skip:(!$IsSupportedEnvironment) { + $configFile = WriteLogSettings -LogId $logId -ScriptBlockLogging -LogLevel Verbose + $script = @' +$pid +& ([scriptblock]::create("Write-Verbose 'testheader123$([char]0x0000)' ;Write-verbose 'after'")) +'@ + $testFileName = 'test01.ps1' + $testScriptPath = Join-Path -Path $TestDrive -ChildPath $testFileName + $script | Out-File -FilePath $testScriptPath -Force + $null = & $powershell -NoProfile -SettingsFile $configFile -Command $testScriptPath + + # Get log entries from the last 100 that match our id and are after the time we launched Powershell + $items = Get-PSSysLog -Path $SyslogFile -Id $logId -Tail 100 -Verbose -TotalCount 18 + + $items | Should -Not -Be $null + $items.Count | Should -BeGreaterThan 2 + $createdEvents = $items | where-object {$_.EventId -eq 'ScriptBlock_Compile_Detail:ExecuteCommand.Create.Verbose'} + $createdEvents.Count | should -BeGreaterOrEqual 3 + + # Verify we log that we are executing a file + $createdEvents[0].Message | Should -Match ($scriptBlockCreatedRegExTemplate -f ".*/$testFileName") + + # Verify we log that we are the script to create the scriptblock + $createdEvents[1].Message | Should -Match ($scriptBlockCreatedRegExTemplate -f (Get-RegEx -SimpleMatch $Script.Replace([System.Environment]::NewLine,'#012'))) + + # Verify we log that we are excuting the created scriptblock + $createdEvents[2].Message | Should -Match ($scriptBlockCreatedRegExTemplate -f "Write\-Verbose 'testheader123␀' ;Write\-verbose 'after'") + } + It 'Verifies logging level filtering works' -Skip:(!$IsSupportedEnvironment) { $configFile = WriteLogSettings -LogId $logId -LogLevel Warning & $powershell -NoProfile -SettingsFile $configFile -Command '$env:PSModulePath | out-null' From 9f4760244e1a1e87d36e44e514028e0a753b83d5 Mon Sep 17 00:00:00 2001 From: Travis Plunk Date: Fri, 24 Aug 2018 14:24:11 -0700 Subject: [PATCH 4/5] Add test case for windows script block logging with null character --- test/powershell/Host/Logging.Tests.ps1 | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/test/powershell/Host/Logging.Tests.ps1 b/test/powershell/Host/Logging.Tests.ps1 index 5cd54ddcc1d..245906f9e07 100644 --- a/test/powershell/Host/Logging.Tests.ps1 +++ b/test/powershell/Host/Logging.Tests.ps1 @@ -441,6 +441,11 @@ Describe 'Basic EventLog tests on Windows' -Tag @('CI','RequireAdminOnWindows') script = "Write-Verbose 'testheader123' ;Write-verbose 'after'" expectedText="Write-Verbose 'testheader123' ;Write-verbose 'after'`r`n" } + @{ + name = 'script block with Null' + script = "Write-Verbose 'testheader123$([char]0x0000)' ;Write-verbose 'after'" + expectedText="Write-Verbose 'testheader123␀' ;Write-verbose 'after'`r`n" + } ) if ($IsSupportedEnvironment) From 9dbb97309be0bc27067a2ae2a7cee92a31a9dd71 Mon Sep 17 00:00:00 2001 From: Travis Plunk Date: Tue, 13 Nov 2018 10:25:27 -0800 Subject: [PATCH 5/5] Fix CodeFactor issues --- .../engine/runtime/CompiledScriptBlock.cs | 7 +++---- 1 file changed, 3 insertions(+), 4 deletions(-) diff --git a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs index 343f5fbb054..74d543d2d0e 100644 --- a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs +++ b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs @@ -1363,14 +1363,13 @@ private static bool WriteScriptBlockToLog(ScriptBlock scriptBlock, int segment, } } - if(!wasEncoded) + if (!wasEncoded) { // The logging mechanism(s) cannot handle null and rendering may not be able to handle // null as we have the string defined as a null terminated string in the manifest. - // So, replace null characters with the Unicode `SYMBOL FOR NULL` + // So, replace null characters with the Unicode `SYMBOL FOR NULL` // We don't just remove the characters to preserve the fact that a null character was there. - - textToLog = textToLog.Replace('\u0000','\u2400'); + textToLog = textToLog.Replace('\u0000', '\u2400'); } if (scriptBlock._scriptBlockData.HasSuspiciousContent)