Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -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<ProtectedEventLogging>(Utils.SystemWideOnlyConfig);
bool wasEncoded = false;
if (logSetting != null)
{
lock (s_syncObject)
Expand All @@ -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);
Expand All @@ -1355,11 +1357,21 @@ 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,
Expand Down
72 changes: 72 additions & 0 deletions test/powershell/Host/Logging.Tests.ps1
Original file line number Diff line number Diff line change
Expand Up @@ -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'
Expand Down Expand Up @@ -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 {
Expand Down Expand Up @@ -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)
Expand Down