commit 1898da0b657585d2e6399ef783ecb667eed280f9 parent bfcee8edba2853f5a11e96dd7c7f6b412afef26a Author: JohnMcPMS <johnmcp@microsoft.com> Date: Mon, 20 Mar 2023 17:15:45 -0700 Add diagnostics to the processor component (#3087) This change adds the same diagnostics event to the `IConfigurationSetProcessorFactory` as the `ConfigurationProcessor` already has. It also adds a property to control the minimum level of events, enabling filtering to be done at event publishing rather than consumption. All of the public facing methods in the processor component are enlightened to send any escaping exceptions to the diagnostics before letting them generate an error. Additionally, verbose logs are added throughout to enable a better understanding of what/when things are happening. Diffstat:
24 files changed, 418 insertions(+), 120 deletions(-)
diff --git a/src/AppInstallerCLICore/ConfigurationSetProcessorFactoryRemoting.cpp b/src/AppInstallerCLICore/ConfigurationSetProcessorFactoryRemoting.cpp @@ -3,6 +3,7 @@ #include "pch.h" #include "ConfigurationSetProcessorFactoryRemoting.h" +using namespace winrt::Windows::Foundation; using namespace winrt::Microsoft::Management::Configuration; namespace AppInstaller::CLI::Workflow::ConfigurationRemoting @@ -38,6 +39,8 @@ namespace AppInstaller::CLI::Workflow::ConfigurationRemoting { RemoteFactory() { + AICLI_LOG(Config, Verbose, << "Launching process for configuration processing..."); + // Security attributes to set handles as inherited. SECURITY_ATTRIBUTES securityAttributes{}; securityAttributes.nLength = sizeof(securityAttributes); @@ -75,6 +78,7 @@ namespace AppInstaller::CLI::Workflow::ConfigurationRemoting wil::unique_process_information processInformation; THROW_IF_WIN32_BOOL_FALSE(CreateProcessW(serverPath.c_str(), &arguments[0], nullptr, nullptr, TRUE, DETACHED_PROCESS, nullptr, nullptr, &startupInfo, &processInformation)); + AICLI_LOG(Config, Verbose, << " Configuration remote PID is " << processInformation.dwProcessId); HANDLE waitHandles[2]; waitHandles[0] = initEvent.get(); @@ -123,8 +127,9 @@ namespace AppInstaller::CLI::Workflow::ConfigurationRemoting THROW_IF_FAILED(stream->Write(mappedMemory->FactoryObject, mappedMemory->FactorySize, nullptr)); THROW_IF_FAILED(stream->Seek({}, STREAM_SEEK_SET, nullptr)); - wil::com_ptr<IUnknown> output; + wil::com_ptr<::IUnknown> output; THROW_IF_FAILED(CoUnmarshalInterface(stream.get(), winrt::guid_of<IConfigurationSetProcessorFactory>(), reinterpret_cast<void**>(&output))); + AICLI_LOG(Config, Verbose, << "... configuration processing connection established."); m_remoteFactory = IConfigurationSetProcessorFactory{ output.detach(), winrt::take_ownership_from_abi }; } @@ -133,6 +138,26 @@ namespace AppInstaller::CLI::Workflow::ConfigurationRemoting return m_remoteFactory.CreateSetProcessor(configurationSet); } + winrt::event_token Diagnostics(const EventHandler<DiagnosticInformation>& handler) + { + return m_remoteFactory.Diagnostics(handler); + } + + void Diagnostics(const winrt::event_token& token) noexcept + { + m_remoteFactory.Diagnostics(token); + } + + DiagnosticLevel MinimumLevel() + { + return m_remoteFactory.MinimumLevel(); + } + + void MinimumLevel(DiagnosticLevel value) + { + m_remoteFactory.MinimumLevel(value); + } + private: IConfigurationSetProcessorFactory m_remoteFactory; wil::unique_mutex m_completionMutex; @@ -163,7 +188,7 @@ HRESULT WindowsPackageManagerConfigurationCompleteOutOfProcessFactoryInitializat wil::com_ptr<IStream> stream; RETURN_IF_FAILED(CreateStreamOnHGlobal(nullptr, TRUE, &stream)); - RETURN_IF_FAILED(CoMarshalInterface(stream.get(), winrt::guid_of<IConfigurationSetProcessorFactory>(), reinterpret_cast<IUnknown*>(factory), MSHCTX_LOCAL, nullptr, MSHLFLAGS_NORMAL)); + RETURN_IF_FAILED(CoMarshalInterface(stream.get(), winrt::guid_of<IConfigurationSetProcessorFactory>(), reinterpret_cast<::IUnknown*>(factory), MSHCTX_LOCAL, nullptr, MSHLFLAGS_NORMAL)); ULARGE_INTEGER streamSize{}; RETURN_IF_FAILED(stream->Seek({}, STREAM_SEEK_CUR, &streamSize)); diff --git a/src/AppInstallerCLICore/Workflows/ConfigurationFlow.cpp b/src/AppInstallerCLICore/Workflows/ConfigurationFlow.cpp @@ -43,6 +43,20 @@ namespace AppInstaller::CLI::Workflow return Logging::Level::Info; } + DiagnosticLevel ConvertLevel(Logging::Level level) + { + switch (level) + { + case Logging::Level::Verbose: return DiagnosticLevel::Verbose; + case Logging::Level::Info: return DiagnosticLevel::Informational; + case Logging::Level::Warning: return DiagnosticLevel::Warning; + case Logging::Level::Error: return DiagnosticLevel::Error; + case Logging::Level::Crit: return DiagnosticLevel::Critical; + } + + return DiagnosticLevel::Informational; + } + Resource::StringId ToResource(ConfigurationUnitIntent intent) { switch (intent) @@ -102,7 +116,7 @@ namespace AppInstaller::CLI::Workflow break; default: // TODO: Sort out how we actually want to handle this given that we don't expect anything but strings - out << " [PropertyType="_liv << property.Type() << "]\n"_liv; + out << " [Debug:PropertyType="_liv << property.Type() << "]\n"_liv; break; } } @@ -337,6 +351,7 @@ namespace AppInstaller::CLI::Workflow { AICLI_LOG(Config, Error, << "Configuration unit " << Utility::ConvertToUTF8(unit.UnitName()) << "[" << Utility::ConvertToUTF8(unit.Identifier()) << "] failed with code 0x" << Logging::SetHRFormat << resultInformation.ResultCode() << " and error message:\n" << Utility::ConvertToUTF8(resultInformation.Description())); + // TODO: Improve error reporting for failures: use message, known HRs, getting HR system string, etc. m_context.Reporter.Error() << " "_liv << Resource::String::ConfigurationUnitFailed << " 0x"_liv << Logging::SetHRFormat << resultInformation.ResultCode() << std::endl; } OutputUnitCompletionProgress(); @@ -383,6 +398,9 @@ namespace AppInstaller::CLI::Workflow { ConfigurationProcessor processor{ CreateConfigurationSetProcessorFactory() }; + // Set the processor to the current level of the logging. + processor.MinimumLevel(ConvertLevel(Logging::Log().GetLevel())); + // Route the configuration diagnostics into the context's diagnostics logging processor.Diagnostics([&context](const winrt::Windows::Foundation::IInspectable&, const DiagnosticInformation& diagnostics) { @@ -429,7 +447,15 @@ namespace AppInstaller::CLI::Workflow AICLI_TERMINATE_CONTEXT(openResult.ResultCode()); } - context.Get<Data::ConfigurationContext>().Set(openResult.Set()); + ConfigurationSet result = openResult.Set(); + + // Fill out the information about the set based on it coming from a file. + // TODO: Consider how to properly determine a good value for name and origin. + result.Name(absolutePath.filename().wstring()); + result.Origin(absolutePath.parent_path().wstring()); + result.Path(absolutePath.wstring()); + + context.Get<Data::ConfigurationContext>().Set(result); } void ShowConfigurationSet(Context& context) diff --git a/src/AppInstallerCLITests/TestConfiguration.cpp b/src/AppInstallerCLITests/TestConfiguration.cpp @@ -21,6 +21,25 @@ namespace TestCommon } } + winrt::event_token TestConfigurationSetProcessorFactory::Diagnostics(const EventHandler<DiagnosticInformation>& handler) + { + return m_diagnostics.add(handler); + } + + void TestConfigurationSetProcessorFactory::Diagnostics(const winrt::event_token& token) noexcept + { + m_diagnostics.remove(token); + } + + DiagnosticLevel TestConfigurationSetProcessorFactory::MinimumLevel() + { + return DiagnosticLevel::Informational; + } + + void TestConfigurationSetProcessorFactory::MinimumLevel(DiagnosticLevel) + { + } + IConfigurationUnitProcessorDetails TestConfigurationSetProcessor::GetUnitProcessorDetails(const ConfigurationUnit& unit, ConfigurationUnitDetailLevel detailLevel) { if (GetUnitProcessorDetailsFunc) diff --git a/src/AppInstallerCLITests/TestConfiguration.h b/src/AppInstallerCLITests/TestConfiguration.h @@ -13,7 +13,16 @@ namespace TestCommon { winrt::Microsoft::Management::Configuration::IConfigurationSetProcessor CreateSetProcessor(const winrt::Microsoft::Management::Configuration::ConfigurationSet& configurationSet); + winrt::event_token Diagnostics(const winrt::Windows::Foundation::EventHandler<winrt::Microsoft::Management::Configuration::DiagnosticInformation>& handler); + void Diagnostics(const winrt::event_token& token) noexcept; + + winrt::Microsoft::Management::Configuration::DiagnosticLevel MinimumLevel(); + void MinimumLevel(winrt::Microsoft::Management::Configuration::DiagnosticLevel value); + std::function<winrt::Microsoft::Management::Configuration::IConfigurationSetProcessor(const winrt::Microsoft::Management::Configuration::ConfigurationSet&)> CreateSetProcessorFunc; + + private: + winrt::event<winrt::Windows::Foundation::EventHandler<winrt::Microsoft::Management::Configuration::DiagnosticInformation>> m_diagnostics; }; struct TestConfigurationSetProcessor : winrt::implements<TestConfigurationSetProcessor, winrt::Microsoft::Management::Configuration::IConfigurationSetProcessor> diff --git a/src/AppInstallerSharedLib/AppInstallerLogging.cpp b/src/AppInstallerSharedLib/AppInstallerLogging.cpp @@ -102,6 +102,11 @@ namespace AppInstaller::Logging m_enabledLevel = level; } + Level DiagnosticLogger::GetLevel() const + { + return m_enabledLevel; + } + bool DiagnosticLogger::IsEnabled(Channel channel, Level level) const { return (!m_loggers.empty() && diff --git a/src/AppInstallerSharedLib/Public/AppInstallerLogging.h b/src/AppInstallerSharedLib/Public/AppInstallerLogging.h @@ -135,6 +135,9 @@ namespace AppInstaller::Logging // For example; SetLevel(Verbose) will enable all logs. void SetLevel(Level level); + // Gets the enabled level. + Level GetLevel() const; + // Checks whether a given channel and level are enabled. bool IsEnabled(Channel channel, Level level) const; diff --git a/src/Microsoft.Management.Configuration.Processor/Exceptions/FindDscResourceNotFoundException.cs b/src/Microsoft.Management.Configuration.Processor/Exceptions/FindDscResourceNotFoundException.cs @@ -7,6 +7,7 @@ namespace Microsoft.Management.Configuration.Processor.Exceptions { using System; + using Microsoft.PowerShell.Commands; /// <summary> /// Resource not found by Find-DscResource. @@ -16,16 +17,24 @@ namespace Microsoft.Management.Configuration.Processor.Exceptions /// <summary> /// Initializes a new instance of the <see cref="FindDscResourceNotFoundException"/> class. /// </summary> - /// <param name="unitName">Unit name.</param> - public FindDscResourceNotFoundException(string unitName) + /// <param name="resourceName">Resource name.</param> + /// <param name="module">Optional module.</param> + public FindDscResourceNotFoundException(string resourceName, ModuleSpecification? module) + : base($"Could not find resource: {resourceName} [{module?.ToString() ?? "<no module>"}]") { this.HResult = ErrorCodes.WinGetConfigUnitNotFoundRepository; - this.UnitName = unitName; + this.ResourceName = resourceName; + this.Module = module; } /// <summary> - /// Gets the unit name. + /// Gets the resource name. /// </summary> - public string UnitName { get; } + public string ResourceName { get; } + + /// <summary> + /// Gets the module, if any. + /// </summary> + public ModuleSpecification? Module { get; } } } diff --git a/src/Microsoft.Management.Configuration.Processor/Exceptions/GetDscResourceMultipleMatches.cs b/src/Microsoft.Management.Configuration.Processor/Exceptions/GetDscResourceMultipleMatches.cs @@ -20,6 +20,7 @@ namespace Microsoft.Management.Configuration.Processor.Exceptions /// <param name="resourceName">Resource name.</param> /// <param name="module">Optional module.</param> public GetDscResourceMultipleMatches(string resourceName, ModuleSpecification? module) + : base($"Multiple matches found for resource: {resourceName} [{module?.ToString() ?? "<no module>"}]") { this.HResult = ErrorCodes.WinGetConfigUnitMultipleMatches; this.ResourceName = resourceName; diff --git a/src/Microsoft.Management.Configuration.Processor/Exceptions/InstallDscResourceException.cs b/src/Microsoft.Management.Configuration.Processor/Exceptions/InstallDscResourceException.cs @@ -20,6 +20,7 @@ namespace Microsoft.Management.Configuration.Processor.Exceptions /// <param name="resourceName">Resource name.</param> /// <param name="module">Module.</param> public InstallDscResourceException(string resourceName, ModuleSpecification? module) + : base($"Unable to find resource after install: {resourceName} [{module?.ToString() ?? "<no module>"}]") { this.HResult = ErrorCodes.WinGetConfigUnitNotFound; this.ResourceName = resourceName; diff --git a/src/Microsoft.Management.Configuration.Processor/Exceptions/InvokeDscResourceGetException.cs b/src/Microsoft.Management.Configuration.Processor/Exceptions/InvokeDscResourceGetException.cs @@ -20,6 +20,7 @@ namespace Microsoft.Management.Configuration.Processor.Exceptions /// <param name="resourceName">Resource name.</param> /// <param name="module">Optional module.</param> public InvokeDscResourceGetException(string resourceName, ModuleSpecification? module) + : base($"Failed when calling `Get` for resource: {resourceName} [{module?.ToString() ?? "<no module>"}]") { this.HResult = ErrorCodes.WinGetConfigUnitInvokeGet; this.ResourceName = resourceName; diff --git a/src/Microsoft.Management.Configuration.Processor/Exceptions/InvokeDscResourceSetException.cs b/src/Microsoft.Management.Configuration.Processor/Exceptions/InvokeDscResourceSetException.cs @@ -20,6 +20,7 @@ namespace Microsoft.Management.Configuration.Processor.Exceptions /// <param name="resourceName">Resource name.</param> /// <param name="module">Optional module.</param> public InvokeDscResourceSetException(string resourceName, ModuleSpecification? module) + : base($"Failed when calling `Set` for resource: {resourceName} [{module?.ToString() ?? "<no module>"}]") { this.HResult = ErrorCodes.WinGetConfigUnitInvokeSet; this.ResourceName = resourceName; diff --git a/src/Microsoft.Management.Configuration.Processor/Exceptions/InvokeDscResourceTestException.cs b/src/Microsoft.Management.Configuration.Processor/Exceptions/InvokeDscResourceTestException.cs @@ -20,6 +20,7 @@ namespace Microsoft.Management.Configuration.Processor.Exceptions /// <param name="resourceName">Resource name.</param> /// <param name="module">Optional module.</param> public InvokeDscResourceTestException(string resourceName, ModuleSpecification? module) + : base($"Failed when calling `Test` for resource: {resourceName} [{module?.ToString() ?? "<no module>"}]") { this.HResult = ErrorCodes.WinGetConfigUnitInvokeTest; this.ResourceName = resourceName; diff --git a/src/Microsoft.Management.Configuration.Processor/Helpers/ConfigurationUnitAndResource.cs b/src/Microsoft.Management.Configuration.Processor/Helpers/ConfigurationUnitAndResource.cs @@ -18,7 +18,6 @@ namespace Microsoft.Management.Configuration.Processor.Helpers /// </summary> internal class ConfigurationUnitAndResource { - private readonly ConfigurationUnitInternal configurationUnitInternal; private readonly DscResourceInfoInternal dscResourceInfoInternal; /// <summary> @@ -35,16 +34,21 @@ namespace Microsoft.Management.Configuration.Processor.Helpers throw new ArgumentException(); } - this.configurationUnitInternal = configurationUnitInternal; + this.UnitInternal = configurationUnitInternal; this.dscResourceInfoInternal = dscResourceInfoInternal; } /// <summary> + /// Gets or initializes the internal unit. + /// </summary> + public ConfigurationUnitInternal UnitInternal { get; private init; } + + /// <summary> /// Gets the configuration unit. /// </summary> public ConfigurationUnit Unit { - get { return this.configurationUnitInternal.Unit; } + get { return this.UnitInternal.Unit; } } /// <summary> @@ -52,7 +56,7 @@ namespace Microsoft.Management.Configuration.Processor.Helpers /// </summary> public IReadOnlyDictionary<string, object>? DirectivesOverlay { - get { return this.configurationUnitInternal.DirectivesOverlay; } + get { return this.UnitInternal.DirectivesOverlay; } } /// <summary> @@ -69,7 +73,7 @@ namespace Microsoft.Management.Configuration.Processor.Helpers /// </summary> public ModuleSpecification? Module { - get { return this.configurationUnitInternal.Module; } + get { return this.UnitInternal.Module; } } /// <summary> @@ -79,7 +83,7 @@ namespace Microsoft.Management.Configuration.Processor.Helpers /// <returns>The value of the directive. Null if doesn't exist.</returns> public string? GetDirective(string directiveName) { - return this.configurationUnitInternal.GetDirective(directiveName); + return this.UnitInternal.GetDirective(directiveName); } /// <summary> diff --git a/src/Microsoft.Management.Configuration.Processor/Helpers/ConfigurationUnitInternal.cs b/src/Microsoft.Management.Configuration.Processor/Helpers/ConfigurationUnitInternal.cs @@ -63,6 +63,15 @@ namespace Microsoft.Management.Configuration.Processor.Helpers public ModuleSpecification? Module { get; } /// <summary> + /// Creates a string that identifies this unit for diagnostics. + /// </summary> + /// <returns>The string that identifies this unit for diagnostics.</returns> + public string ToIdentifyingString() + { + return $"{this.Unit.UnitName} [{this.Module?.ToString() ?? "<no module>"}]"; + } + + /// <summary> /// Get a directive from the unit taking into account the directives overlay. /// </summary> /// <param name="directiveName">Directive name.</param> diff --git a/src/Microsoft.Management.Configuration.Processor/ProcessorEnvironments/HostedEnvironment.cs b/src/Microsoft.Management.Configuration.Processor/ProcessorEnvironments/HostedEnvironment.cs @@ -59,7 +59,7 @@ namespace Microsoft.Management.Configuration.Processor.Runspaces // Only support PowerShell Core. if (this.GetVariable<string>(Variables.PSEdition) != Core) { - throw new NotSupportedException(); + throw new NotSupportedException("Only PowerShell Core is supported."); } var powerShellGet = PowerShellHelpers.CreateModuleSpecification( diff --git a/src/Microsoft.Management.Configuration.Processor/Public/ConfigurationSetProcessorFactory.cs b/src/Microsoft.Management.Configuration.Processor/Public/ConfigurationSetProcessorFactory.cs @@ -6,6 +6,7 @@ namespace Microsoft.Management.Configuration.Processor { + using System; using Microsoft.Management.Configuration; using Microsoft.Management.Configuration.Processor.ProcessorEnvironments; using Microsoft.Management.Configuration.Processor.Set; @@ -30,26 +31,65 @@ namespace Microsoft.Management.Configuration.Processor } /// <summary> + /// Diagnostics event; useful for logging and/or verbose output. + /// </summary> + public event EventHandler<DiagnosticInformation>? Diagnostics; + + /// <summary> + /// Gets or sets the minimum diagnostic level to send. + /// </summary> + public DiagnosticLevel MinimumLevel { get; set; } = DiagnosticLevel.Informational; + + /// <summary> /// Gets the configuration unit processor details for the given unit. /// </summary> /// <param name="set">Configuration Set.</param> /// <returns>Configuration set processor.</returns> public IConfigurationSetProcessor CreateSetProcessor(ConfigurationSet set) { - var envFactory = new ProcessorEnvironmentFactory(this.type); - var processorEnvironment = envFactory.CreateEnvironment(); - processorEnvironment.ValidateRunspace(); - - if (this.properties is not null) + try { - var additionalPsModulePaths = this.properties.AdditionalModulePaths; - if (additionalPsModulePaths is not null) + this.OnDiagnostics(DiagnosticLevel.Verbose, $"Creating set processor for `{set.Name}`..."); + + var envFactory = new ProcessorEnvironmentFactory(this.type); + var processorEnvironment = envFactory.CreateEnvironment(); + processorEnvironment.ValidateRunspace(); + + if (this.properties is not null) { - processorEnvironment.PrependPSModulePaths(additionalPsModulePaths); + var additionalPsModulePaths = this.properties.AdditionalModulePaths; + if (additionalPsModulePaths is not null) + { + processorEnvironment.PrependPSModulePaths(additionalPsModulePaths); + } } + + this.OnDiagnostics(DiagnosticLevel.Verbose, "... done creating set processor."); + + return new ConfigurationSetProcessor(processorEnvironment, set) { SetProcessorFactory = this }; + } + catch (Exception ex) + { + this.OnDiagnostics(DiagnosticLevel.Error, ex.ToString()); + throw; } + } - return new ConfigurationSetProcessor(processorEnvironment, set); + /// <summary> + /// Sends diagnostics if appropriate. + /// </summary> + /// <param name="level">The level of this diagnostic message.</param> + /// <param name="message">The diagnostic message.</param> + internal void OnDiagnostics(DiagnosticLevel level, string message) + { + EventHandler<DiagnosticInformation>? diagnostics = this.Diagnostics; + if (diagnostics != null && level >= this.MinimumLevel) + { + DiagnosticInformation information = new DiagnosticInformation(); + information.Level = level; + information.Message = message; + diagnostics.Invoke(this, information); + } } } } \ No newline at end of file diff --git a/src/Microsoft.Management.Configuration.Processor/Set/ConfigurationSetProcessor.cs b/src/Microsoft.Management.Configuration.Processor/Set/ConfigurationSetProcessor.cs @@ -36,6 +36,11 @@ namespace Microsoft.Management.Configuration.Processor.Set } /// <summary> + /// Gets or initializes the set processor factory. + /// </summary> + internal ConfigurationSetProcessorFactory? SetProcessorFactory { get; init; } + + /// <summary> /// Gets the processor environment. /// </summary> internal IProcessorEnvironment ProcessorEnvironment { get; } @@ -50,13 +55,24 @@ namespace Microsoft.Management.Configuration.Processor.Set ConfigurationUnit unit, IReadOnlyDictionary<string, object>? directivesOverlay) { - var configurationUnitInternal = new ConfigurationUnitInternal(unit, directivesOverlay); + try + { + var configurationUnitInternal = new ConfigurationUnitInternal(unit, directivesOverlay); + this.OnDiagnostics(DiagnosticLevel.Verbose, $"Creating unit processor for: {configurationUnitInternal.ToIdentifyingString()}..."); - var dscResourceInfo = this.PrepareUnitForProcessing(configurationUnitInternal); + var dscResourceInfo = this.PrepareUnitForProcessing(configurationUnitInternal); - return new ConfigurationUnitProcessor( - this.ProcessorEnvironment, - new ConfigurationUnitAndResource(configurationUnitInternal, dscResourceInfo)); + this.OnDiagnostics(DiagnosticLevel.Verbose, "... done creating unit processor."); + return new ConfigurationUnitProcessor( + this.ProcessorEnvironment, + new ConfigurationUnitAndResource(configurationUnitInternal, dscResourceInfo)) + { SetProcessorFactory = this.SetProcessorFactory }; + } + catch (Exception ex) + { + this.OnDiagnostics(DiagnosticLevel.Error, ex.ToString()); + throw; + } } /// <summary> @@ -69,81 +85,90 @@ namespace Microsoft.Management.Configuration.Processor.Set ConfigurationUnit unit, ConfigurationUnitDetailLevel detailLevel) { - var unitInternal = new ConfigurationUnitInternal(unit); - var dscResourceInfo = this.ProcessorEnvironment.GetDscResource(unitInternal); - - if (dscResourceInfo is not null) + try { - return this.GetUnitProcessorDetailsLocal( - unit.UnitName, - dscResourceInfo, - detailLevel == ConfigurationUnitDetailLevel.Load); - } + var unitInternal = new ConfigurationUnitInternal(unit); + this.OnDiagnostics(DiagnosticLevel.Verbose, $"Getting unit details [{detailLevel}] for: {unitInternal.ToIdentifyingString()}"); + var dscResourceInfo = this.ProcessorEnvironment.GetDscResource(unitInternal); - if (detailLevel == ConfigurationUnitDetailLevel.Local) - { - // Not found locally. - return null; - } + if (dscResourceInfo is not null) + { + return this.GetUnitProcessorDetailsLocal( + unit.UnitName, + dscResourceInfo, + detailLevel == ConfigurationUnitDetailLevel.Load); + } - var getFindResource = this.ProcessorEnvironment.FindDscResource(unitInternal); - if (getFindResource is null) - { - // Not found in catalog. - return null; - } + if (detailLevel == ConfigurationUnitDetailLevel.Local) + { + // Not found locally. + return null; + } - // Hopefully they will never change the properties name. If someone can explain to me - // why assign it Name to $_ in Find-DscResource turns into a string in PowerShell but - // into a PSObject here that would be nice... - dynamic findResource = getFindResource; - string findResourceName = findResource.Name.ToString(); + var getFindResource = this.ProcessorEnvironment.FindDscResource(unitInternal); + if (getFindResource is null) + { + // Not found in catalog. + return null; + } - if (detailLevel == ConfigurationUnitDetailLevel.Catalog) - { - return new ConfigurationUnitProcessorDetails( - findResourceName, - null, - null, - findResource.PSGetModuleInfo, - null); - } + // Hopefully they will never change the properties name. If someone can explain to me + // why assign it Name to $_ in Find-DscResource turns into a string in PowerShell but + // into a PSObject here that would be nice... + dynamic findResource = getFindResource; + string findResourceName = findResource.Name.ToString(); - if (detailLevel == ConfigurationUnitDetailLevel.Download) - { - var tempSavePath = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString()); - Directory.CreateDirectory(tempSavePath); - this.ProcessorEnvironment.SaveModule(getFindResource, tempSavePath); + if (detailLevel == ConfigurationUnitDetailLevel.Catalog) + { + return new ConfigurationUnitProcessorDetails( + findResourceName, + null, + null, + findResource.PSGetModuleInfo, + null); + } - var moduleInfo = this.ProcessorEnvironment.GetAvailableModule( - Path.Combine(tempSavePath, findResource.PSGetModuleInfo.Name)); + if (detailLevel == ConfigurationUnitDetailLevel.Download) + { + var tempSavePath = Path.Combine(Path.GetTempPath(), Guid.NewGuid().ToString()); + Directory.CreateDirectory(tempSavePath); + this.ProcessorEnvironment.SaveModule(getFindResource, tempSavePath); + + var moduleInfo = this.ProcessorEnvironment.GetAvailableModule( + Path.Combine(tempSavePath, findResource.PSGetModuleInfo.Name)); + + return new ConfigurationUnitProcessorDetails( + findResourceName, + null, + moduleInfo, + findResource.PSGetModuleInfo, + this.GetCertificates(moduleInfo)); + } - return new ConfigurationUnitProcessorDetails( - findResourceName, - null, - moduleInfo, - findResource.PSGetModuleInfo, - this.GetCertificates(moduleInfo)); - } + if (detailLevel == ConfigurationUnitDetailLevel.Load) + { + this.ProcessorEnvironment.InstallModule(getFindResource); - if (detailLevel == ConfigurationUnitDetailLevel.Load) - { - this.ProcessorEnvironment.InstallModule(getFindResource); + dscResourceInfo = this.ProcessorEnvironment.GetDscResource(unitInternal); - dscResourceInfo = this.ProcessorEnvironment.GetDscResource(unitInternal); + if (dscResourceInfo is null) + { + // Well, this is awkward. + throw new InstallDscResourceException( + unit.UnitName, + PowerShellHelpers.CreateModuleSpecification(findResource.ModuleName, findResource.Version)); + } - if (dscResourceInfo is null) - { - // Well, this is awkward. - throw new InstallDscResourceException( - unit.UnitName, - PowerShellHelpers.CreateModuleSpecification(findResource.ModuleName, findResource.Version)); + return this.GetUnitProcessorDetailsLocal(unit.UnitName, dscResourceInfo, true); } - return this.GetUnitProcessorDetailsLocal(unit.UnitName, dscResourceInfo, true); + return null; + } + catch (Exception ex) + { + this.OnDiagnostics(DiagnosticLevel.Error, ex.ToString()); + throw; } - - return null; } private DscResourceInfoInternal PrepareUnitForProcessing(ConfigurationUnitInternal unitInternal) @@ -164,7 +189,7 @@ namespace Microsoft.Management.Configuration.Processor.Set if (findDscResourceResult is null) { - throw new FindDscResourceNotFoundException(unitInternal.Unit.UnitName); + throw new FindDscResourceNotFoundException(unitInternal.Unit.UnitName, unitInternal.Module); } this.ProcessorEnvironment.InstallModule(findDscResourceResult); @@ -243,5 +268,10 @@ namespace Microsoft.Management.Configuration.Processor.Set return this.ProcessorEnvironment.GetCertsOfValidSignedFiles(paths.ToArray()); } + + private void OnDiagnostics(DiagnosticLevel level, string message) + { + this.SetProcessorFactory?.OnDiagnostics(level, message); + } } } diff --git a/src/Microsoft.Management.Configuration.Processor/Unit/ConfigurationUnitProcessor.cs b/src/Microsoft.Management.Configuration.Processor/Unit/ConfigurationUnitProcessor.cs @@ -47,12 +47,19 @@ namespace Microsoft.Management.Configuration.Processor.Unit public IReadOnlyDictionary<string, object>? DirectivesOverlay => this.unitResource.DirectivesOverlay; /// <summary> + /// Gets or initializes the set processor factory. + /// </summary> + internal ConfigurationSetProcessorFactory? SetProcessorFactory { get; init; } + + /// <summary> /// Gets the current system state for the configuration unit. /// Calls Get on the DSC resource. /// </summary> /// <returns>A <see cref="GetSettingsResult"/>.</returns> public GetSettingsResult GetSettings() { + this.OnDiagnostics(DiagnosticLevel.Verbose, $"Invoking `Get` for resource: {this.unitResource.UnitInternal.ToIdentifyingString()}..."); + var result = new GetSettingsResult(); try { @@ -64,15 +71,24 @@ namespace Microsoft.Management.Configuration.Processor.Unit catch (Exception e) when (e is RuntimeException || e is WriteErrorException) { + RuntimeException? re = e as RuntimeException; + if (re != null) + { + this.OnDiagnostics(DiagnosticLevel.Error, $"An error occurred within the configuration unit when attempting `Get`:\n{re.ErrorRecord.ToString()}\n{re.ErrorRecord.ScriptStackTrace}"); + } + + this.OnDiagnostics(DiagnosticLevel.Verbose, e.ToString()); var inner = e.GetMostInnerException(); result.ResultInformation.ResultCode = inner; result.ResultInformation.Description = e.ToString(); } - catch (Exception) + catch (Exception e) { + this.OnDiagnostics(DiagnosticLevel.Error, e.ToString()); throw; } + this.OnDiagnostics(DiagnosticLevel.Verbose, $"... done invoking `Get`."); return result; } @@ -83,8 +99,11 @@ namespace Microsoft.Management.Configuration.Processor.Unit /// <returns>A <see cref="TestSettingsResult"/>.</returns> public TestSettingsResult TestSettings() { + this.OnDiagnostics(DiagnosticLevel.Verbose, $"Invoking `Test` for resource: {this.unitResource.UnitInternal.ToIdentifyingString()}..."); + if (this.Unit.Intent == ConfigurationUnitIntent.Inform) { + this.OnDiagnostics(DiagnosticLevel.Error, "`Test` should not be called on a unit with intent of `Inform`"); throw new NotSupportedException(); } @@ -102,15 +121,24 @@ namespace Microsoft.Management.Configuration.Processor.Unit catch (Exception e) when (e is RuntimeException || e is WriteErrorException) { + RuntimeException? re = e as RuntimeException; + if (re != null) + { + this.OnDiagnostics(DiagnosticLevel.Error, $"An error occurred within the configuration unit when attempting `Test`:\n{re.ErrorRecord.ToString()}\n{re.ErrorRecord.ScriptStackTrace}"); + } + + this.OnDiagnostics(DiagnosticLevel.Verbose, e.ToString()); var inner = e.GetMostInnerException(); result.ResultInformation.ResultCode = inner; result.ResultInformation.Description = e.ToString(); } - catch (Exception) + catch (Exception e) { + this.OnDiagnostics(DiagnosticLevel.Error, e.ToString()); throw; } + this.OnDiagnostics(DiagnosticLevel.Verbose, $"... done invoking `Test`."); return result; } @@ -121,9 +149,12 @@ namespace Microsoft.Management.Configuration.Processor.Unit /// <returns>A <see cref="ApplySettingsResult"/>.</returns> public ApplySettingsResult ApplySettings() { + this.OnDiagnostics(DiagnosticLevel.Verbose, $"Invoking `Apply` for resource: {this.unitResource.UnitInternal.ToIdentifyingString()}..."); + if (this.Unit.Intent == ConfigurationUnitIntent.Inform || this.Unit.Intent == ConfigurationUnitIntent.Assert) { + this.OnDiagnostics(DiagnosticLevel.Error, $"`Apply` should not be called on a unit with intent of `{this.Unit.Intent}`"); throw new NotSupportedException(); } @@ -138,16 +169,30 @@ namespace Microsoft.Management.Configuration.Processor.Unit catch (Exception e) when (e is RuntimeException || e is WriteErrorException) { + RuntimeException? re = e as RuntimeException; + if (re != null) + { + this.OnDiagnostics(DiagnosticLevel.Error, $"An error occurred within the configuration unit when attempting `Set`:\n{re.ErrorRecord.ToString()}\n{re.ErrorRecord.ScriptStackTrace}"); + } + + this.OnDiagnostics(DiagnosticLevel.Verbose, e.ToString()); var inner = e.GetMostInnerException(); result.ResultInformation.ResultCode = inner; result.ResultInformation.Description = e.ToString(); } - catch (Exception) + catch (Exception e) { + this.OnDiagnostics(DiagnosticLevel.Error, e.ToString()); throw; } + this.OnDiagnostics(DiagnosticLevel.Verbose, $"... done invoking `Apply`."); return result; } + + private void OnDiagnostics(DiagnosticLevel level, string message) + { + this.SetProcessorFactory?.OnDiagnostics(level, message); + } } } diff --git a/src/Microsoft.Management.Configuration.UnitTests/Helpers/TestConfigurationProcessorFactory.cs b/src/Microsoft.Management.Configuration.UnitTests/Helpers/TestConfigurationProcessorFactory.cs @@ -23,6 +23,16 @@ namespace Microsoft.Management.Configuration.UnitTests.Helpers internal delegate IConfigurationSetProcessor CreateSetProcessorDelegateType(TestConfigurationProcessorFactory factory, ConfigurationSet configurationSet); /// <summary> + /// Diagnostics event; useful for logging and/or verbose output. + /// </summary> + public event EventHandler<DiagnosticInformation>? Diagnostics; + + /// <summary> + /// Gets or sets the minimum diagnostic level to send. + /// </summary> + public DiagnosticLevel MinimumLevel { get; set; } = DiagnosticLevel.Informational; + + /// <summary> /// Gets or sets the processor used when the incoming configuration set is null. /// </summary> internal TestConfigurationSetProcessor? NullProcessor { get; set; } diff --git a/src/Microsoft.Management.Configuration/ConfigurationProcessor.cpp b/src/Microsoft.Management.Configuration/ConfigurationProcessor.cpp @@ -99,6 +99,15 @@ namespace winrt::Microsoft::Management::Configuration::implementation logger.EnableChannel(AppInstaller::Logging::Channel::All); logger.SetLevel(AppInstaller::Logging::Level::Verbose); logger.AddLogger(std::make_unique<ConfigurationProcessorDiagnosticsLogger>(*this)); + + if (m_factory) + { + m_factoryDiagnosticsEventRevoker = m_factory.Diagnostics(winrt::auto_revoke, + [this](const IInspectable&, const DiagnosticInformation& information) + { + m_diagnostics(*this, information); + }); + } } event_token ConfigurationProcessor::Diagnostics(const Windows::Foundation::EventHandler<DiagnosticInformation>& handler) @@ -112,6 +121,17 @@ namespace winrt::Microsoft::Management::Configuration::implementation m_diagnostics.remove(token); } + DiagnosticLevel ConfigurationProcessor::MinimumLevel() + { + return m_minimumLevel; + } + + void ConfigurationProcessor::MinimumLevel(DiagnosticLevel value) + { + m_minimumLevel = value; + m_factory.MinimumLevel(value); + } + event_token ConfigurationProcessor::ConfigurationChange(const Windows::Foundation::TypedEventHandler<ConfigurationSet, ConfigurationChangeData>& handler) { return m_configurationChange.add(handler); @@ -418,8 +438,11 @@ namespace winrt::Microsoft::Management::Configuration::implementation void ConfigurationProcessor::Diagnostics(DiagnosticLevel level, std::string_view message) { - auto diagnostics = make_self<wil::details::module_count_wrapper<implementation::DiagnosticInformation>>(); - diagnostics->Initialize(level, AppInstaller::Utility::ConvertToUTF16(message)); - m_diagnostics(*this, *diagnostics); + if (level >= m_minimumLevel) + { + auto diagnostics = make_self<wil::details::module_count_wrapper<implementation::DiagnosticInformation>>(); + diagnostics->Initialize(level, AppInstaller::Utility::ConvertToUTF16(message)); + m_diagnostics(*this, *diagnostics); + } } } diff --git a/src/Microsoft.Management.Configuration/ConfigurationProcessor.h b/src/Microsoft.Management.Configuration/ConfigurationProcessor.h @@ -30,6 +30,9 @@ namespace winrt::Microsoft::Management::Configuration::implementation event_token Diagnostics(const Windows::Foundation::EventHandler<DiagnosticInformation>& handler); void Diagnostics(const event_token& token) noexcept; + DiagnosticLevel MinimumLevel(); + void MinimumLevel(DiagnosticLevel value); + event_token ConfigurationChange(const Windows::Foundation::TypedEventHandler<ConfigurationSet, ConfigurationChangeData>& handler); void ConfigurationChange(const event_token& token) noexcept; @@ -70,6 +73,8 @@ namespace winrt::Microsoft::Management::Configuration::implementation event<Windows::Foundation::EventHandler<DiagnosticInformation>> m_diagnostics; event<Windows::Foundation::TypedEventHandler<ConfigurationSet, ConfigurationChangeData>> m_configurationChange; ConfigThreadGlobals m_threadGlobals; + IConfigurationSetProcessorFactory::Diagnostics_revoker m_factoryDiagnosticsEventRevoker; + DiagnosticLevel m_minimumLevel = DiagnosticLevel::Informational; #endif }; } diff --git a/src/Microsoft.Management.Configuration/DiagnosticInformation.cpp b/src/Microsoft.Management.Configuration/DiagnosticInformation.cpp @@ -6,19 +6,29 @@ namespace winrt::Microsoft::Management::Configuration::implementation { - void DiagnosticInformation::Initialize(DiagnosticLevel level, std::wstring_view message) - { - m_level = level; - m_message = message; - } + void DiagnosticInformation::Initialize(DiagnosticLevel level, std::wstring_view message) + { + m_level = level; + m_message = message; + } + + DiagnosticLevel DiagnosticInformation::Level() + { + return m_level; + } - DiagnosticLevel DiagnosticInformation::Level() - { - return m_level; - } + void DiagnosticInformation::Level(DiagnosticLevel value) + { + m_level = value; + } + + hstring DiagnosticInformation::Message() + { + return m_message; + } - hstring DiagnosticInformation::Message() - { - return m_message; + void DiagnosticInformation::Message(const hstring& value) + { + m_message = value; } } diff --git a/src/Microsoft.Management.Configuration/DiagnosticInformation.h b/src/Microsoft.Management.Configuration/DiagnosticInformation.h @@ -14,7 +14,10 @@ namespace winrt::Microsoft::Management::Configuration::implementation #endif DiagnosticLevel Level(); + void Level(DiagnosticLevel value); + hstring Message(); + void Message(const hstring& value); #if !defined(INCLUDE_ONLY_INTERFACE_METHODS) private: @@ -23,3 +26,10 @@ namespace winrt::Microsoft::Management::Configuration::implementation #endif }; } + +namespace winrt::Microsoft::Management::Configuration::factory_implementation +{ + struct DiagnosticInformation : DiagnosticInformationT<DiagnosticInformation, implementation::DiagnosticInformation> + { + }; +} diff --git a/src/Microsoft.Management.Configuration/Microsoft.Management.Configuration.idl b/src/Microsoft.Management.Configuration/Microsoft.Management.Configuration.idl @@ -350,14 +350,6 @@ namespace Microsoft.Management.Configuration IConfigurationUnitProcessor CreateUnitProcessor(ConfigurationUnit unit, Windows.Foundation.Collections.IMapView<String, Object> directivesOverlay); } - // Allows different runtimes to provide specialized handling of configuration processing. - [contract(Microsoft.Management.Configuration.Contract, 1)] - interface IConfigurationSetProcessorFactory - { - // Creates a configuration set processor for the given set. - IConfigurationSetProcessor CreateSetProcessor(ConfigurationSet configurationSet); - } - // The level of the diagnostic information. [contract(Microsoft.Management.Configuration.Contract, 1)] enum DiagnosticLevel @@ -373,11 +365,27 @@ namespace Microsoft.Management.Configuration [contract(Microsoft.Management.Configuration.Contract, 1)] runtimeclass DiagnosticInformation { + DiagnosticInformation(); + // Indicates the importance of the diagnostic information. - DiagnosticLevel Level{ get; }; + DiagnosticLevel Level; // The diagnostic message. - String Message{ get; }; + String Message; + } + + // Allows different runtimes to provide specialized handling of configuration processing. + [contract(Microsoft.Management.Configuration.Contract, 1)] + interface IConfigurationSetProcessorFactory + { + // Creates a configuration set processor for the given set. + IConfigurationSetProcessor CreateSetProcessor(ConfigurationSet configurationSet); + + // Diagnostics event; useful for logging and/or verbose output. + event Windows.Foundation.EventHandler<DiagnosticInformation> Diagnostics; + + // Indicates the minimum importance desired for diagnostics. + DiagnosticLevel MinimumLevel; } // The change event type that has occurred. @@ -583,6 +591,9 @@ namespace Microsoft.Management.Configuration // Diagnostics event; useful for logging and/or verbose output. event Windows.Foundation.EventHandler<DiagnosticInformation> Diagnostics; + // Indicates the minimum importance desired for diagnostics. + DiagnosticLevel MinimumLevel; + // Only top level configuration changes are sent to this event. // This includes things like: creation of a new set for intent to run, start/stop of a set for application or test, deletion of a not started set. event Windows.Foundation.TypedEventHandler<ConfigurationSet, ConfigurationChangeData> ConfigurationChange;