admin/PowerShell-PowerShell
1
0
Fork 0
mirror of https://github.com/PowerShell/PowerShell synced 2026-06-08 12:12:50 +00:00
Code Issues Packages Projects Releases Wiki Activity

Rewrite the mac syslog tests to make them less flaky (#21174)

Browse Source
This commit is contained in:
James Truher [MSFT]
2024-02-07 13:09:41 -08:00
committed by GitHub
parent 79639822c4
commit 0919240822
2 changed files with 53 additions and 56 deletions
Download Patch File Download Diff File Expand all files Collapse all files
test/powershell/Host/Logging.Tests.ps1
+51 -55
View File
@@ -43,6 +43,29 @@ enum LogKeyword
ManagedPlugin = 0x100
}
# mac log command can emit json, so just use that
# we need to deconstruct the eventmessage to get the event id
# we also need to filter out the non-default messages
function Get-MacOsSyslogItems {
param ([int]$processId, [string]$logId)
$logArgs = "show", "--process", "$processId", "--style", "json"
log $logArgs |
ConvertFrom-Json |
Where-Object { $_.category -eq "$logId" -and $_.messageType -eq "Default" } |
ForEach-Object {
$s = $_.eventMessage.IndexOf('[') + 1
$e = $_.EventMessage.IndexOf(']')
$l = $e - $s
if ($l -gt 0) {
$eventId = $_.eventMessage.SubString($s, $l)
}
else {
$eventId = "unknown"
}
$_ | Add-Member -MemberType NoteProperty -Name EventId -Value $eventId -PassThru
}
}
<#
.SYNOPSIS
Creates a powershell.config.json file with syslog settings
@@ -317,26 +340,19 @@ Path:.*
}
}
It 'Verifies basic logging with no customizations' -Skip:(!$IsSupportedEnvironment) {
It 'Verifies basic logging with no customizations' -Skip:(!$IsMacOS) {
try {
$timeString = [DateTime]::Now.ToString('yyyy-MM-dd HH:mm:ss')
$configFile = WriteLogSettings -LogId $logId
copy-item $configFile /tmp/pwshtest.config.json
$testPid = & $powershell -NoProfile -SettingsFile $configFile -Command '$PID'
Export-PSOsLog -After $after -LogPid $testPid -TimeoutInMilliseconds 30000 -IntervalInMilliseconds 3000 -MinimumCount 3 |
Set-Content -Path $contentFile
$items = @(Get-PSOsLog -Path $contentFile -Id $logId -After $after -TotalCount 3 -Verbose)
$items = Get-MacOsSyslogItems -processId $testPid -logId $logId
$items | Should -Not -Be $null
$items.Count | Should -BeGreaterThan 2
$items[0].EventId | Should -BeExactly 'Perftrack_ConsoleStartupStart:PowershellConsoleStartup.WinStart.Informational'
$items[1].EventId | Should -BeExactly 'NamedPipeIPC_ServerListenerStarted:NamedPipe.Open.Informational'
$items[2].EventId | Should -BeExactly 'Perftrack_ConsoleStartupStop:PowershellConsoleStartup.WinStop.Informational'
# if there are more items than expected...
if ($items.Count -gt 3)
{
# Force reporting of the first unexpected item to help diagnosis
$items[3] | Should -Be $null
}
$items.EventId | Should -Contain 'Perftrack_ConsoleStartupStart:PowershellConsoleStartup.WinStart.Informational'
$items.EventId | Should -Contain 'NamedPipeIPC_ServerListenerStarted:NamedPipe.Open.Informational'
$items.EventId | Should -Contain 'Perftrack_ConsoleStartupStop:PowershellConsoleStartup.WinStop.Informational'
}
catch {
if (Test-Path $contentFile) {
@@ -346,7 +362,7 @@ Path:.*
}
}
It 'Verifies scriptblock logging' -Skip:(!$IsSupportedEnvironment) {
It 'Verifies scriptblock logging' -Skip:(!$IsMacOS) {
try {
$script = @'
$PID
@@ -357,24 +373,23 @@ $PID
$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 17 |
Set-Content -Path $contentFile
$items = @(Get-PSOsLog -Path $contentFile -Id $logId -After $after -Verbose)
$items = Get-MacOsSyslogItems -processId $testPid -logId $logId
$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
$createdEvents | ConvertTo-Json | set-content /tmp/createdEvents.json
# Verify we log that we are executing a file
$createdEvents[0].Message | Should -Match ($scriptBlockCreatedRegExTemplate -f ".*/$testFileName")
$createdEvents[0].EventMessage | Should -Match $testFileName
# Verify we log that we are the script to create the scriptblock
$createdEvents[1].Message | Should -Match ($scriptBlockCreatedRegExTemplate -f (Get-RegEx -SimpleMatch $Script))
$createdEvents[1].EventMessage | Should -Match (Get-RegEx -SimpleMatch $Script)
# Verify we log that we are executing the created scriptblock
$createdEvents[2].Message | Should -Match ($scriptBlockCreatedRegExTemplate -f "Write\-Verbose 'testheader123' ;Write\-verbose 'after'")
$createdEvents[2].EventMessage | Should -Match "Write-Verbose 'testheader123' ;Write-verbose 'after'"
}
catch {
if (Test-Path $contentFile) {
@@ -384,35 +399,28 @@ $PID
}
}
It 'Verifies scriptblock logging with null character' -Skip:(!$IsSupportedEnvironment) {
It 'Verifies scriptblock logging with null character' -Skip:(!$IsMacOS) {
try {
$script = @'
$PID
& ([scriptblock]::create("Write-Verbose 'testheader123$([char]0x0000)' ;Write-verbose 'after'"))
'@
$configFile = WriteLogSettings -ScriptBlockLogging -LogId $logId -LogLevel Verbose
$testFileName = 'test01.ps1'
$testFileName = 'test02.ps1'
$testScriptPath = Join-Path -Path $TestDrive -ChildPath $testFileName
$script | Out-File -FilePath $testScriptPath -Force
$testPid = & $powershell -NoProfile -SettingsFile $configFile -Command $testScriptPath
$testPid = & $powershell -NoProfile -SettingsFile $configFile -Command $testScriptPath | Select-Object -First 1
Export-PSOsLog -After $after -LogPid $testPid -TimeoutInMilliseconds 30000 -IntervalInMilliseconds 3000 -MinimumCount 17 |
Set-Content -Path $contentFile
$items = @(Get-PSOsLog -Path $contentFile -Id $logId -After $after -Verbose)
$items = Get-MacOsSyslogItems -processId $testPid -logId $logId
$items | convertto-json | set-content /tmp/items.json
$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")
$createdEvents[0].EventMessage | Should -Match $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 executing the created scriptblock
$createdEvents[2].Message | Should -Match ($scriptBlockCreatedRegExTemplate -f "Write\-Verbose 'testheader123␀' ;Write\-verbose 'after'")
# Verify we log the null in the message
$createdEvents[1].EventMessage | Should -Match "Write-Verbose 'testheader123\`$\(\[char\]0x0000\)' ;Write-verbose 'after'"
}
catch {
if (Test-Path $contentFile) {
@@ -422,25 +430,13 @@ $PID
}
}
# This is pending because it results in false postitives (-Skip:(!$IsSupportedEnvironment) )
It 'Verifies logging level filtering works' -Pending {
try {
$configFile = WriteLogSettings -LogId $logId -LogLevel Warning
$testPid = & $powershell -NoLogo -NoProfile -SettingsFile $configFile -Command '$PID'
# this is now specific to MacOS
It 'Verifies logging level filtering works' -skip:(!$IsMacOs) {
$configFile = WriteLogSettings -LogId $logId -LogLevel Warning
$testPid = & $powershell -NoLogo -NoProfile -SettingsFile $configFile -Command '$PID'
Export-PSOsLog -After $after -LogPid $testPid |
Set-Content -Path $contentFile
# by default, powershell startup should only logs informational events.
# With Level = Warning, nothing should be logged.
$items = Get-PSOsLog -Path $contentFile -Id $logId -After $after -TotalCount 3
$items | Should -Be $null
}
catch {
if (Test-Path $contentFile) {
Send-VstsLogFile -Path $contentFile
}
throw
}
$items = Get-MacOsSyslogItems -processId $testPid -logId $logId
$items | Should -Be $null -Because ("{0} Warning event logs were found" -f @($items).Count)
}
}
test/tools/Modules/PSSysLog/PSSysLog.psm1
+2 -1
View File
@@ -438,7 +438,8 @@ class PSLogItem
if($item.LogId -notmatch '^\[com\.microsoft\.powershell')
{
Write-Verbose "Skipping logId: $($item.LogId)" -Verbose
# this is really a lot of output, so we'll skip it for now.
# Write-Verbose "Skipping logId: $($item.LogId)" -Verbose
$result = $null
break
}