diff --git a/.travis.yml b/.travis.yml index 0ae6e7163..e08b163bf 100644 --- a/.travis.yml +++ b/.travis.yml @@ -8,8 +8,10 @@ matrix: - os: linux dist: trusty sudo: required + env: TRAVIS_CI_CACHE_NAME=linux - os: osx - osx_image: xcode8.1 + osx_image: xcode9.4 + env: TRAVIS_CI_CACHE_NAME=macOS fast_finish: true addons: diff --git a/src/Microsoft.PowerShell.ConsoleHost/host/msh/CommandLineParameterParser.cs b/src/Microsoft.PowerShell.ConsoleHost/host/msh/CommandLineParameterParser.cs index d2929fff4..d22f53ace 100644 --- a/src/Microsoft.PowerShell.ConsoleHost/host/msh/CommandLineParameterParser.cs +++ b/src/Microsoft.PowerShell.ConsoleHost/host/msh/CommandLineParameterParser.cs @@ -200,6 +200,7 @@ namespace Microsoft.PowerShell _helpText = helpText; } + #region Internal properties internal bool AbortStartup { get @@ -393,6 +394,205 @@ namespace Microsoft.PowerShell get { return _workingDirectory; } } + #endregion Internal properties + + #region static methods + /// + /// Processes the -SettingFile Argument. + /// + /// + /// The command line parameters to be processed. + /// + /// + /// The index in args to the argument following '-SettingFile'. + /// + /// + /// Used to allow the helper to write errors to the console. If not supplied, no errors will be written. + /// + /// + /// Returns true if the argument was parsed successfully and false if not. + /// + private static bool TryParseSettingFileHelper(string[] args, int settingFileArgIndex, CommandLineParameterParser parser) + { + if (settingFileArgIndex >= args.Length) + { + if (parser != null) + { + parser.WriteCommandLineError( + CommandLineParameterParserStrings.MissingSettingsFileArgument); + } + + return false; + } + + string configFile = null; + try + { + configFile = NormalizeFilePath(args[settingFileArgIndex]); + } + catch (Exception ex) + { + if (parser != null) + { + string error = string.Format(CultureInfo.CurrentCulture, CommandLineParameterParserStrings.InvalidSettingsFileArgument, args[settingFileArgIndex], ex.Message); + parser.WriteCommandLineError(error); + } + + return false; + } + + if (!System.IO.File.Exists(configFile)) + { + if (parser != null) + { + string error = string.Format(CultureInfo.CurrentCulture, CommandLineParameterParserStrings.SettingsFileNotExists, configFile); + parser.WriteCommandLineError(error); + } + + return false; + } + PowerShellConfig.Instance.SetSystemConfigFilePath(configFile); + return true; + } + + /// + /// Processes the command line parameters to ConsoleHost which must be parsed before the Host is created. + /// Success to indicate that the program should continue running. + /// + /// + /// The command line parameters to be processed. + /// + internal static void EarlyParse(string[] args) + { + // indicates that we've called this method on this instance, and that when it's done, the state variables + // will reflect the parse. + + EarlyParseHelper(args); + } + + private static string GetConfigurationNameFromGroupPolicy() + { + // Current user policy takes precedence. + var consoleSessionSetting = Utils.GetPolicySetting(Utils.CurrentUserThenSystemWideConfig); + + return (consoleSessionSetting?.EnableConsoleSessionConfiguration == true && !string.IsNullOrEmpty(consoleSessionSetting?.ConsoleSessionConfigurationName)) ? + consoleSessionSetting.ConsoleSessionConfigurationName : string.Empty; + } + + /// + /// Processes the command line parameters to ConsoleHost which must be parsed before the Host is created. + /// Success to indicate that the program should continue running. + /// + /// + /// The command line parameters to be processed. + /// + private static void EarlyParseHelper(string[] args) + { + if(args == null) + { + Dbg.Assert(args != null, "Argument 'args' to EarlyParseHelper should never be null"); + return; + } + + bool noexitSeen = false; + for (int i = 0; i < args.Length; ++i) + { + (string SwitchKey, bool ShouldBreak) switchKeyResults = GetSwitchKey(args, ref i, parser: null, ref noexitSeen); + if (switchKeyResults.ShouldBreak) + { + break; + } + + string switchKey = switchKeyResults.SwitchKey; + + if (MatchSwitch(switchKey, match: "settingsfile", smallestUnambiguousMatch: "settings")) + { + // parse setting file arg and don't write error as there is no host yet. + if (!TryParseSettingFileHelper(args, ++i, parser: null)) + { + break; + } + } + } + } + + /// + /// Gets the word in a switch from the current argument or parses a file. + /// For example -foo, /foo, or --foo would return 'foo'. + /// + /// + /// The command line parameters to be processed. + /// + /// + /// The index in args to the argument to process. + /// + /// + /// Used to parse files in the args. If not supplied, Files will not be parsed. + /// + /// + /// Used during parsing files. + /// + /// + /// Returns a Tuple: + /// The first value is a String called SwitchKey with the word in a switch from the current argument or null. + /// The second value is a bool called ShouldBreak, indicating if the parsing look should break. + /// + private static (string SwitchKey, bool ShouldBreak) GetSwitchKey(string[] args, ref int argIndex, CommandLineParameterParser parser, ref bool noexitSeen) + { + string switchKey = args[argIndex].Trim().ToLowerInvariant(); + if (string.IsNullOrEmpty(switchKey)) + { + return (SwitchKey: null, ShouldBreak: false); + } + + if (!SpecialCharacters.IsDash(switchKey[0]) && switchKey[0] != '/') + { + // then its a file + if (parser != null) + { + --argIndex; + parser.ParseFile(args, ref argIndex, noexitSeen); + } + + return (SwitchKey: null, ShouldBreak: true); + } + + // chop off the first character so that we're agnostic wrt specifying / or - + // in front of the switch name. + switchKey = switchKey.Substring(1); + + // chop off the second dash so we're agnostic wrt specifying - or -- + if (!string.IsNullOrEmpty(switchKey) && SpecialCharacters.IsDash(switchKey[0])) + { + switchKey = switchKey.Substring(1); + } + + return (SwitchKey: switchKey, ShouldBreak: false); + } + + private static string NormalizeFilePath(string path) + { + // Normalize slashes + path = path.Replace(StringLiterals.AlternatePathSeparator, + StringLiterals.DefaultPathSeparator); + + return Path.GetFullPath(path); + } + + private static bool MatchSwitch(string switchKey, string match, string smallestUnambiguousMatch) + { + Dbg.Assert(switchKey != null, "need a value"); + Dbg.Assert(!String.IsNullOrEmpty(match), "need a value"); + Dbg.Assert(match.Trim().ToLowerInvariant() == match, "match should be normalized to lowercase w/ no outside whitespace"); + Dbg.Assert(smallestUnambiguousMatch.Trim().ToLowerInvariant() == smallestUnambiguousMatch, "match should be normalized to lowercase w/ no outside whitespace"); + Dbg.Assert(match.Contains(smallestUnambiguousMatch), "sUM should be a substring of match"); + + return (match.Trim().ToLowerInvariant().IndexOf(switchKey, StringComparison.Ordinal) == 0 && + switchKey.Length >= smallestUnambiguousMatch.Length); + } + + #endregion + private void ShowHelp() { Dbg.Assert(_helpText != null, "_helpText should not be null"); @@ -463,24 +663,6 @@ namespace Microsoft.PowerShell } } - private static string GetConfigurationNameFromGroupPolicy() - { - // Current user policy takes precedence. - var consoleSessionSetting = Utils.GetPolicySetting(Utils.CurrentUserThenSystemWideConfig); - if (consoleSessionSetting != null) - { - if (consoleSessionSetting.EnableConsoleSessionConfiguration == true) - { - if (!string.IsNullOrEmpty(consoleSessionSetting.ConsoleSessionConfigurationName)) - { - return consoleSessionSetting.ConsoleSessionConfigurationName; - } - } - } - - return string.Empty; - } - private void ParseHelper(string[] args) { Dbg.Assert(args != null, "Argument 'args' to ParseHelper should never be null"); @@ -488,32 +670,13 @@ namespace Microsoft.PowerShell for (int i = 0; i < args.Length; ++i) { - // Invariant culture used because command-line parameters are not localized. - - string switchKey = args[i].Trim().ToLowerInvariant(); - if (String.IsNullOrEmpty(switchKey)) + (string SwitchKey, bool ShouldBreak) switchKeyResults = GetSwitchKey(args, ref i, this, ref noexitSeen); + if (switchKeyResults.ShouldBreak) { - continue; - } - - if (!SpecialCharacters.IsDash(switchKey[0]) && switchKey[0] != '/') - { - // then its a file - - --i; - ParseFile(args, ref i, noexitSeen); break; } - // chop off the first character so that we're agnostic wrt specifying / or - - // in front of the switch name. - switchKey = switchKey.Substring(1); - - // chop off the second dash so we're agnostic wrt specifying - or -- - if (!String.IsNullOrEmpty(switchKey) && SpecialCharacters.IsDash(switchKey[0])) - { - switchKey = switchKey.Substring(1); - } + string switchKey = switchKeyResults.SwitchKey; // If version is in the commandline, don't continue to look at any other parameters if (MatchSwitch(switchKey, "version", "v")) @@ -711,34 +874,13 @@ namespace Microsoft.PowerShell } } - else if (MatchSwitch(switchKey, "settingsfile", "settings") ) + else if (MatchSwitch(switchKey, "settingsfile", "settings")) { - ++i; - if (i >= args.Length) + // Parse setting file arg and write error + if (!TryParseSettingFileHelper(args, ++i, this)) { - WriteCommandLineError( - CommandLineParameterParserStrings.MissingSettingsFileArgument); break; } - string configFile = null; - try - { - configFile = NormalizeFilePath(args[i]); - } - catch (Exception ex) - { - string error = string.Format(CultureInfo.CurrentCulture, CommandLineParameterParserStrings.InvalidSettingsFileArgument, args[i], ex.Message); - WriteCommandLineError(error); - break; - } - - if (!System.IO.File.Exists(configFile)) - { - string error = string.Format(CultureInfo.CurrentCulture, CommandLineParameterParserStrings.SettingsFileNotExists, configFile); - WriteCommandLineError(error); - break; - } - PowerShellConfig.Instance.SetSystemConfigFilePath(configFile); } #if STAMODE // explicit setting of the ApartmentState Not supported on NanoServer @@ -818,25 +960,6 @@ namespace Microsoft.PowerShell _exitCode = ConsoleHost.ExitCodeBadCommandLineParameter; } - private bool MatchSwitch(string switchKey, string match, string smallestUnambiguousMatch) - { - Dbg.Assert(switchKey != null, "need a value"); - Dbg.Assert(!String.IsNullOrEmpty(match), "need a value"); - Dbg.Assert(match.Trim().ToLowerInvariant() == match, "match should be normalized to lowercase w/ no outside whitespace"); - Dbg.Assert(smallestUnambiguousMatch.Trim().ToLowerInvariant() == smallestUnambiguousMatch, "match should be normalized to lowercase w/ no outside whitespace"); - Dbg.Assert(match.Contains(smallestUnambiguousMatch), "sUM should be a substring of match"); - - if (match.Trim().ToLowerInvariant().IndexOf(switchKey, StringComparison.Ordinal) == 0) - { - if (switchKey.Length >= smallestUnambiguousMatch.Length) - { - return true; - } - } - - return false; - } - private void ParseFormat(string[] args, ref int i, ref Serialization.DataFormat format, string resourceStr) { StringBuilder sb = new StringBuilder(); @@ -892,15 +1015,6 @@ namespace Microsoft.PowerShell executionPolicy = args[i]; } - private static string NormalizeFilePath(string path) - { - // Normalize slashes - path = path.Replace(StringLiterals.AlternatePathSeparator, - StringLiterals.DefaultPathSeparator); - - return Path.GetFullPath(path); - } - private bool ParseFile(string[] args, ref int i, bool noexitSeen) { // Process file execution. We don't need to worry about checking -command diff --git a/src/Microsoft.PowerShell.ConsoleHost/host/msh/ConsoleHost.cs b/src/Microsoft.PowerShell.ConsoleHost/host/msh/ConsoleHost.cs index d6a96d907..bf198a602 100644 --- a/src/Microsoft.PowerShell.ConsoleHost/host/msh/ConsoleHost.cs +++ b/src/Microsoft.PowerShell.ConsoleHost/host/msh/ConsoleHost.cs @@ -148,6 +148,12 @@ namespace Microsoft.PowerShell try { + // We need to read the settings file before we create the console host + string[] tempArgs = new string[args.GetLength(0)]; + args.CopyTo(tempArgs, 0); + + CommandLineParameterParser.EarlyParse(tempArgs); + // We might be able to ignore console host creation error if we are running in // server mode, which does not require a console. HostException hostException = null; @@ -168,8 +174,6 @@ namespace Microsoft.PowerShell s_cpp = new CommandLineParameterParser( (s_theConsoleHost != null) ? s_theConsoleHost.UI : (new NullHostUserInterface()), bannerText, helpText); - string[] tempArgs = new string[args.GetLength(0)]; - args.CopyTo(tempArgs, 0); s_cpp.Parse(tempArgs); diff --git a/src/System.Management.Automation/singleshell/config/MshSnapinInfo.cs b/src/System.Management.Automation/singleshell/config/MshSnapinInfo.cs index 199fc5e1f..b69ad6827 100644 --- a/src/System.Management.Automation/singleshell/config/MshSnapinInfo.cs +++ b/src/System.Management.Automation/singleshell/config/MshSnapinInfo.cs @@ -967,7 +967,12 @@ namespace System.Management.Automation strongName, moduleName, psVersion, assemblyVersion, types, formats, null, s_coreSnapin.Description, s_coreSnapin.DescriptionIndirect, null, null, s_coreSnapin.VendorIndirect, null); +#if !UNIX + // NOTE: On Unix, logging has to be deferred until after command-line parsing + // complete. On Windows, deferring the call is not needed + // and this is in the startup code path. SetSnapInLoggingInformation(coreMshSnapin); +#endif return coreMshSnapin; } diff --git a/test/powershell/Host/Logging.Tests.ps1 b/test/powershell/Host/Logging.Tests.ps1 index ebd6bea6c..a53e21f66 100644 --- a/test/powershell/Host/Logging.Tests.ps1 +++ b/test/powershell/Host/Logging.Tests.ps1 @@ -158,7 +158,7 @@ Describe 'Basic SysLog tests on Linux' -Tag @('CI','RequireSudoOnUnix') { } } -Describe 'Basic os_log tests on MacOS' -Tag @('CI','RequireSudoOnUnix') { +Describe 'Basic os_log tests on MacOS' -Tag @('Feature','RequireSudoOnUnix') { BeforeAll { [bool] $IsSupportedEnvironment = $IsMacOS [bool] $persistenceEnabled = $false @@ -201,34 +201,33 @@ Describe 'Basic os_log tests on MacOS' -Tag @('CI','RequireSudoOnUnix') { } } - ## Logging seems broken on macOS 10.13. It works fine on macOS 10.12.6. - ## Travis CI updated macOS to 10.13.3 (kernel 17.4) and the logging tests start to fail. - # It 'Verifies basic logging with no customizations' -Skip:(!$IsSupportedEnvironment) { - It 'Verifies basic logging with no customizations' -Pending { + It 'Verifies basic logging with no customizations' -Skip:(!$IsSupportedEnvironment) { $configFile = WriteLogSettings -LogId $logId - & $powershell -NoProfile -SettingsFile $configFile -Command '$env:PSModulePath | out-null' + $testPid = & $powershell -NoProfile -SettingsFile $configFile -Command '$PID' - Export-PSOsLog -After $after -Verbose | Set-Content -Path $contentFile - $items = Get-PSOsLog -Path $contentFile -Id $logId -After $after -TotalCount 3 -Verbose + # Made tests more reliable + Start-Sleep -Milliseconds 500 + + Export-PSOsLog -After $after -LogPid $testPid -Verbose | Set-Content -Path $contentFile + $items = @(Get-PSOsLog -Path $contentFile -Id $logId -After $after -TotalCount 3 -Verbose) $items | Should -Not -Be $null - $items.Length | Should -BeGreaterThan 1 + $items.Count | Should -BeGreaterThan 1 $items[0].EventId | Should -BeExactly 'Perftrack_ConsoleStartupStart:PowershellConsoleStartup.WinStart.Informational' $items[1].EventId | Should -BeExactly 'Perftrack_ConsoleStartupStop:PowershellConsoleStartup.WinStop.Informational' # if there are more items than expected... - if ($items.Length -gt 2) + if ($items.Count -gt 2) { # Force reporting of the first unexpected item to help diagnosis $items[2] | Should -Be $null } } - # It 'Verifies logging level filtering works' -Skip:(!$IsSupportedEnvironment) { - It 'Verifies logging level filtering works' -Pending { + It 'Verifies logging level filtering works' -Skip:(!$IsSupportedEnvironment) { $configFile = WriteLogSettings -LogId $logId -LogLevel Warning - & $powershell -NoProfile -SettingsFile $configFile -Command '$env:PSModulePath | out-null' + $testPid = & $powershell -NoLogo -NoProfile -SettingsFile $configFile -Command '$PID' - Export-PSOsLog -After $after -Verbose | Set-Content -Path $contentFile + Export-PSOsLog -After $after -LogPid $testPid -Verbose | 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 diff --git a/test/tools/Modules/PSSysLog/PSSysLog.psm1 b/test/tools/Modules/PSSysLog/PSSysLog.psm1 index 3c19ae12a..dcddcf7c0 100644 --- a/test/tools/Modules/PSSysLog/PSSysLog.psm1 +++ b/test/tools/Modules/PSSysLog/PSSysLog.psm1 @@ -142,22 +142,34 @@ enum SysLogIds # Defines the array indices when calling # String.Split on an OsLog log entry -enum OsLogIds +Class OsLogIds { - Date = 0; - Time = 1; - Thread = 2; - Type = 3; - Activity = 4; - Pid = 5; - ProcessName = 6; - Module = 7; - Id = 8; - CommitId = 9; - EventId = 10; - Message = 11; + [int] $Date = 0; + [int] $Time = 1; + [int] $Thread = 2; + [int] $Type = 3; + [int] $Activity = 4; + [int] $Pid = 5; + [int] $TTL = 6; + [int] $ProcessName = 7; + [int] $Module = 8; + [int] $Id = 9; + [int] $CommitId = 10; + [int] $EventId = 11; + [int] $Message = 12; + + [void] UseOldIds() + { + $this.ProcessName=6; + $this.Module =7; + $this.Id =8; + $this.CommitId=9; + $this.EventId=10; + $this.Message=11; + } } + class PSLogItem { [string] $LogId = [string]::Empty @@ -336,12 +348,13 @@ class PSLogItem 3: Type Default 4: activity 0x12 5: PID 39437 - 6: processname pwsh: - 7: sourcedll (libpsl-native.dylib) - 8: log source [com.microsoft.powershell.powershell] - 9: commitid:treadid:channel (v6.0.1:1:10) - 10:[EventId] [Perftrack_ConsoleStartupStart:PowershellConsoleStartup.WinStart.Informational] - 11:Message Text + 6: TTL (introduced in ~ 10.13) 0 + 7: processname pwsh: + 8: sourcedll (libpsl-native.dylib) + 9: log source [com.microsoft.powershell.powershell] + 10: commitid:treadid:channel (v6.0.1:1:10) + 11:[EventId] [Perftrack_ConsoleStartupStart:PowershellConsoleStartup.WinStart.Informational] + 12:Message Text #> [object] $result = $content @@ -382,17 +395,28 @@ class PSLogItem $item.Count = 1 $item.Timestamp = $time - $item.ProcessId = [int]::Parse($parts[[OsLogIds]::Pid]) - $item.Message = $parts[[OsLogIds]::Message] + $osLogIds = [OsLogIds]::new(); + $item.ProcessId = [int]::Parse($parts[$osLogIds.Pid]) + + # Around macOS 13, Apple added a field + # Detect if the field is the old or new field and if it is old + # Switch to the old schema + if($parts[$osLogIds.TTL] -match '\:') + { + $osLogIds.UseOldIds() + } + + $item.Message = $parts[$osLogIds.Message] # [com.microsoft.powershell.logid] $splitChars = ('[', '.', ']') - $item.LogId = $parts[[OsLogIds]::Id] + + $item.LogId = $parts[$osLogIds.Id] $subparts = $item.LogId.Split($splitChars, [StringSplitOptions]::RemoveEmptyEntries) if ($subparts.Length -eq 4) { $item.LogId = $subparts[3] - if ($id -ne $null -and $id -ne $item.LogId) + if ($null -ne $id -and $id -ne $item.LogId) { # this is not the log id we're looking for. $result = $null @@ -401,7 +425,7 @@ class PSLogItem } # (commitid:TID:ChannelID) $splitChars = ('(', ')', ':', ' ') - $item.CommitId = $parts[[OsLogIds]::CommitId] + $item.CommitId = $parts[$osLogIds.CommitId] $subparts = $item.CommitId.Split($splitChars, [System.StringSplitOptions]::RemoveEmptyEntries) if ($subparts.Count -eq 3) { @@ -416,7 +440,7 @@ class PSLogItem # [EventId] $splitChars = ('[', ']', ' ') - $item.EventId = $parts[[OsLogIds]::EventId] + $item.EventId = $parts[$osLogIds.EventId] $subparts = $item.EventId.Split($splitChars, [System.StringSplitOptions]::RemoveEmptyEntries) if ($subparts.Count -eq 1) { @@ -805,22 +829,41 @@ function Export-PSOsLog [ValidateNotNullOrEmpty()] [DateTime] $After, - [string] $LogId = "powershell" + [string] $LogId = "powershell", + + [int] $LogPid ) + Test-MacOS + # NOTE: The use of double quotes and single quotes for the predicate parameter # is mandatory. Reversing the usage (e.g., single quotes around double quotes) # causes the double quotes to be stripped breaking the predicate syntax expected # by log show + $extraParams = @() + if($LogPid) + { + $extraParams += @( + '--predicate' + "processID == $LogPid" + ) + } if ($After -ne $null) { [string] $startTime = $After.ToString("yyyy-MM-dd HH:mm:ss") - Start-NativeExecution -command {log show --info --start "$startTime" --predicate "subsystem == 'com.microsoft.powershell'"} + $extraParams += @( + '--start' + "$startTime" + ) } - else - { - Start-NativeExecution -command {log show --info --predicate "process == 'pwsh'"} + else { + $extraParams += @( + '--predicate' + "process == 'pwsh'" + ) } + + Start-NativeExecution -command {log show --info @extraParams} } <#