Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Difference in dependency behavior for variables in appsettings.json vs NLog.config #736

Closed
TheXenocide opened this issue Apr 18, 2024 · 4 comments · Fixed by #737
Closed

Comments

@TheXenocide
Copy link

Type: Bug(?)

NLog version: 5.2.8

NLog.Extensions.Logging version: 5.3.8

NLog.Web.AspNetCore version: N/A

Platform: .NET Standard 2.0, .NET Framework 4.8, .NET 8

Current NLog config

Converting from XML:

<nlog>
  <variable name="logDir" value="C:\Logs" />
  <variable name="archiveDir" value="${logDir}\Archive" />
  <variable name="appName" value="${hosted-app-name}${when:when='${hosted-app-name}' == '':inner=${replace:searchFor=.vshost:replaceWith=:regex=false:inner=${processname}}}"/>
  <variable name="appDomainId" value="${appdomain:format={0\}}" />
  <variable name="logName" value="${when:when='${appDomainId}' != '1':inner=${appdomain:format={0\}-{1\}_}}${appName}"/>
  <variable name="MicrosoftLevel" value="${level:lowercase=true:truncate=4:when=level==LogLevel.Info or level==LogLevel.Warn}${when:when=level==LogLevel.Error:inner=fail}${when:when=level==LogLevel.Fatal:inner=crit}${when:when=level==LogLevel.Debug:inner=dbug}" />
  <variable name="MicrosoftLayout" value="${MicrosoftLevel}: ${logger}[${event-properties:EventId_Id:whenEmpty=0}]${newline}      ${message}${onexception:inner=${newline}${exception:format=tostring}}" />
</nlog>

Found while converting to

{
  "NLog": {
    "variables": {
      "logDir": "C:\\Logs",
      "archiveDir": "${logDir}\\Archive",
      "appName": "${hosted-app-name}${when:when='${hosted-app-name}' == '':inner=${replace:searchFor=.vshost:replaceWith=:regex=false:inner=${processname}}}",
      "appDomainId": "${appdomain:format={0\\}}",
      "logName": "${when:when='${appDomainId}' != '1':inner=${appdomain:format={0\\}-{1\\}_}}${appName}",
      "MicrosoftLevel": "${level:lowercase=true:truncate=4:when=level==LogLevel.Info or level==LogLevel.Warn}${when:when=level==LogLevel.Error:inner=fail}${when:when=level==LogLevel.Fatal:inner=crit}${when:when=level==LogLevel.Debug:inner=dbug}",
      "MicrosoftLayout": "${MicrosoftLevel}: ${logger}[${event-properties:EventId_Id:whenEmpty=0}]${newline}      ${message}${onexception:inner=${newline}${exception:format=tostring}}"
    }
  }
}

Expected Result:

Variables can reference each other

Actual Result:

NLog.NLogConfigurationException
  HResult=0x80131500
  Message=Failed to create LayoutRenderer with unknown type-alias: 'logDir' - Verify type-alias and check extension is included.
  Source=NLog
  StackTrace:
   at NLog.Config.FactoryExtensions.CreateInstance[TBaseType](IFactory`1 factory, String typeAlias)
   at NLog.Layouts.LayoutParser.GetLayoutRenderer(String typeName, ConfigurationItemFactory configurationItemFactory, Nullable`1 throwConfigExceptions)
   at NLog.Layouts.LayoutParser.ParseLayoutRenderer(ConfigurationItemFactory configurationItemFactory, SimpleStringReader stringReader, Nullable`1 throwConfigExceptions)
   at NLog.Layouts.LayoutParser.CompileLayout(ConfigurationItemFactory configurationItemFactory, SimpleStringReader sr, Nullable`1 throwConfigExceptions, Boolean isNested, String& text)
   at NLog.Layouts.LayoutParser.CompileLayout(String value, ConfigurationItemFactory configurationItemFactory, Nullable`1 throwConfigExceptions, String& text)
   at NLog.Layouts.SimpleLayout.SetLayoutText(String value, Nullable`1 throwConfigExceptions)
   at NLog.Layouts.SimpleLayout..ctor(String txt, ConfigurationItemFactory configurationItemFactory, Nullable`1 throwConfigExceptions)
   at NLog.Config.LoggingConfigurationParser.CreateSimpleLayout(String layoutText)
   at NLog.Config.LoggingConfigurationParser.ParseVariableElement(ValidatedConfigurationElement variableElement)
   at NLog.Config.LoggingConfigurationParser.ParseNLogSection(ILoggingConfigurationElement configSection)
   at NLog.Config.LoggingConfigurationParser.LoadConfig(ILoggingConfigurationElement nlogConfig, String basePath)
   at NLog.Extensions.Logging.NLogLoggingConfiguration.LoadConfigurationSection(IConfigurationSection nlogConfig)
   at NLog.Extensions.Logging.NLogLoggingConfiguration..ctor(IConfigurationSection nlogConfig, LogFactory logFactory)
   at NLog.Extensions.Logging.RegisterNLogLoggingProvider.<>c__DisplayClass1_0.<TryLoadConfigurationFromSection>b__0(ISetupLoadConfigurationBuilder configBuilder)
   at NLog.SetupBuilderExtensions.LoadConfiguration(ISetupBuilder setupBuilder, Action`1 configBuilder)
   at NLog.Extensions.Logging.RegisterNLogLoggingProvider.TryLoadConfigurationFromSection(NLogLoggerProvider loggerProvider, IConfiguration configuration)
   at NLog.Extensions.Logging.RegisterNLogLoggingProvider.CreateNLogLoggerProvider(IServiceProvider serviceProvider, IConfiguration hostConfiguration, NLogProviderOptions options, LogFactory logFactory)
   at NLog.Extensions.Logging.ConfigureExtensions.CreateNLogLoggerProvider(IServiceProvider serviceProvider, IConfiguration hostConfiguration, NLogProviderOptions options, LogFactory logFactory)
   at NLog.Extensions.Logging.ConfigureExtensions.CreateNLogLoggerProvider(IServiceProvider serviceProvider, IConfiguration hostConfiguration, NLogProviderOptions options)
   at NLog.Extensions.Logging.RegisterNLogLoggingProvider.<>c__DisplayClass0_1.<TryAddNLogLoggingProvider>b__2(IServiceProvider provider, IConfiguration cfg, NLogProviderOptions opt)
   at NLog.Extensions.Logging.RegisterNLogLoggingProvider.<>c__DisplayClass0_0.<TryAddNLogLoggingProvider>b__4(IServiceProvider serviceProvider)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitConstructor(ConstructorCallSite constructorCallSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitConstructor(ConstructorCallSite constructorCallSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.Resolve(ServiceCallSite callSite, ServiceProviderEngineScope scope)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.CreateServiceAccessor(ServiceIdentifier serviceIdentifier)
   at System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(ServiceIdentifier serviceIdentifier, ServiceProviderEngineScope serviceProviderEngineScope)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService(IServiceProvider provider, Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService[T](IServiceProvider provider)
   at Microsoft.Extensions.Hosting.HostBuilder.<>c__DisplayClass35_0.<PopulateServiceCollection>b__2(IServiceProvider _)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSiteMain(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.VisitRootCache(ServiceCallSite callSite, RuntimeResolverContext context)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteVisitor`2.VisitCallSite(ServiceCallSite callSite, TArgument argument)
   at Microsoft.Extensions.DependencyInjection.ServiceLookup.CallSiteRuntimeResolver.Resolve(ServiceCallSite callSite, ServiceProviderEngineScope scope)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.CreateServiceAccessor(ServiceIdentifier serviceIdentifier)
   at System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(ServiceIdentifier serviceIdentifier, ServiceProviderEngineScope serviceProviderEngineScope)
   at Microsoft.Extensions.DependencyInjection.ServiceProvider.GetService(Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService(IServiceProvider provider, Type serviceType)
   at Microsoft.Extensions.DependencyInjection.ServiceProviderServiceExtensions.GetRequiredService[T](IServiceProvider provider)
   at Microsoft.Extensions.Hosting.HostBuilder.ResolveHost(IServiceProvider serviceProvider, DiagnosticListener diagnosticListener)
   at Microsoft.Extensions.Hosting.HostApplicationBuilder.Build()
   at Microsoft.AspNetCore.Builder.WebApplicationBuilder.Build()
   at Program.<Main>$(String[] args)

While writing this up, with some tinkering I was able to identify what I think is the cause of the issue and, in understanding that, I'm not certain if it will be considered a bug or a feature request or maybe just some additional documentation if it's decided that a fix is more work than its worth.

It appears that the main difference here is that NLog.config processes variables in the order they are defined, whereas the appsettings variety seems like it may be processing them in alphabetical order (probably a result of the underlying implementation details of the IConfiguration system). After fixing logDir by renaming it to z-logDir, MicrosoftLayout threw the same exception due to it referencing MicrosoftLevel (these names come straight from the documentation here).

Ideally it would be nice if the variables could still reference each other without needing to consider alphabetical ordering of their names, whether it did some sort of dependency sorting internally while parsing, or if there was a way to help it identify them with some additional json properties or some such.

Workaround:

{
  "NLog": {
    "variables": {
      "logDir": "C:\\Logs",
      "z-archiveDir": "${logDir}\\Archive",
      "appName": "${hosted-app-name}${when:when='${hosted-app-name}' == '':inner=${replace:searchFor=.vshost:replaceWith=:regex=false:inner=${processname}}}",
      "appDomainId": "${appdomain:format={0\\}}",
      "logName": "${when:when='${appDomainId}' != '1':inner=${appdomain:format={0\\}-{1\\}_}}${appName}",
      "MicrosoftLevel": "${level:lowercase=true:truncate=4:when=level==LogLevel.Info or level==LogLevel.Warn}${when:when=level==LogLevel.Error:inner=fail}${when:when=level==LogLevel.Fatal:inner=crit}${when:when=level==LogLevel.Debug:inner=dbug}",
      "z-MicrosoftLayout": "${MicrosoftLevel}: ${logger}[${event-properties:EventId_Id:whenEmpty=0}]${newline}      ${message}${onexception:inner=${newline}${exception:format=tostring}}"
    }
  }
}
@snakefoot
Copy link
Contributor

Yes was also surprised that keys was sorted automatically when I did the initial implementation of loading NLog configuration from appsettings.json-file. The order shown in the config-file is not the order of how they would be parsed.

Since variables has the ability to reference other variables, then I guess one could make some funky logic that tries to produce custom sorting order when recognizing references. But the funky logic should be local in this repository.

Pull requests are wellcome.

@snakefoot
Copy link
Contributor

Created #737 to improve the user-experience, when config-variables depends on other variables.

@snakefoot
Copy link
Contributor

NLog.Extensions.Logging v5.3.9 has been released, that should improve the user-experience when referencing configuration-variables.

@TheXenocide
Copy link
Author

Awesome! Thanks kindly.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants