diff --git a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs index 30dc54bbb1..5ac27cbae3 100644 --- a/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs +++ b/src/System.Management.Automation/engine/runtime/CompiledScriptBlock.cs @@ -1326,6 +1326,7 @@ namespace System.Management.Automation // 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) @@ -1343,6 +1344,7 @@ namespace System.Management.Automation // 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); @@ -1364,11 +1366,22 @@ namespace System.Management.Automation 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, diff --git a/test/powershell/Host/Logging.Tests.ps1 b/test/powershell/Host/Logging.Tests.ps1 index 98e7d23d97..245906f9e0 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' @@ -342,6 +371,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 { @@ -374,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)