From 171e6819cd93a35f20e96fdefe891a58d579ed86 Mon Sep 17 00:00:00 2001 From: Rolf Kristensen Date: Tue, 9 Apr 2019 21:52:31 +0200 Subject: [PATCH 01/57] LogFactory - Reduce code complexity of GetLogger --- src/NLog/Internal/LoggerConfiguration.cs | 8 +-- src/NLog/LogFactory.cs | 90 +++++++++++------------- 2 files changed, 43 insertions(+), 55 deletions(-) diff --git a/src/NLog/Internal/LoggerConfiguration.cs b/src/NLog/Internal/LoggerConfiguration.cs index 39abc87794..9bda807691 100644 --- a/src/NLog/Internal/LoggerConfiguration.cs +++ b/src/NLog/Internal/LoggerConfiguration.cs @@ -46,9 +46,8 @@ internal class LoggerConfiguration /// Initializes a new instance of the class. /// /// The targets by level. - /// Use the old exception log handling of NLog 3.0? - /// - public LoggerConfiguration(TargetWithFilterChain[] targetsByLevel, bool exceptionLoggingOldStyle = false) + /// Use the old exception log handling of NLog 3.0? + public LoggerConfiguration(TargetWithFilterChain[] targetsByLevel, bool exceptionLoggingOldStyle) { _targetsByLevel = targetsByLevel; #pragma warning disable 618 @@ -61,7 +60,7 @@ public LoggerConfiguration(TargetWithFilterChain[] targetsByLevel, bool exceptio /// /// This method was marked as obsolete before NLog 4.3.11 and it will be removed in NLog 5. [Obsolete("This property marked obsolete before v4.3.11 and it will be removed in NLog 5.")] - public bool ExceptionLoggingOldStyle { get; private set; } + public bool ExceptionLoggingOldStyle { get; } /// /// Gets targets for the specified level. @@ -74,7 +73,6 @@ public TargetWithFilterChain GetTargetsForLevel(LogLevel level) { return null; } - return _targetsByLevel[level.Ordinal]; } diff --git a/src/NLog/LogFactory.cs b/src/NLog/LogFactory.cs index 026d223c4d..92064d2a44 100644 --- a/src/NLog/LogFactory.cs +++ b/src/NLog/LogFactory.cs @@ -381,7 +381,7 @@ public Logger GetCurrentClassLogger(Type loggerType) #else var className = StackTraceUsageUtils.GetClassFullName(new StackFrame(1, false)); #endif - return GetLogger(className, loggerType); + return GetLoggerThreadSafe(className, loggerType); } /// @@ -392,7 +392,7 @@ public Logger GetCurrentClassLogger(Type loggerType) /// are not guaranteed to return the same logger reference. public Logger GetLogger(string name) { - return GetLogger(new LoggerCacheKey(name, typeof(Logger))); + return GetLoggerThreadSafe(name, typeof(Logger)); } /// @@ -404,7 +404,7 @@ public Logger GetLogger(string name) /// are not guaranteed to return the same logger reference. public T GetLogger(string name) where T : Logger { - return (T)GetLogger(new LoggerCacheKey(name, typeof(T))); + return (T)GetLoggerThreadSafe(name, typeof(T)); } /// @@ -416,7 +416,7 @@ public Logger GetLogger(string name) /// same argument aren't guaranteed to return the same logger reference. public Logger GetLogger(string name, Type loggerType) { - return GetLogger(new LoggerCacheKey(name, loggerType)); + return GetLoggerThreadSafe(name, loggerType); } /// @@ -739,8 +739,9 @@ internal LoggerConfiguration GetConfigurationForLogger(string name, LoggingConfi } #pragma warning disable 618 - return new LoggerConfiguration(targetsByLevel, configuration != null && configuration.ExceptionLoggingOldStyle); + var exceptionLoggingOldStyle = configuration?.ExceptionLoggingOldStyle == true; #pragma warning restore 618 + return new LoggerConfiguration(targetsByLevel, exceptionLoggingOldStyle); } /// @@ -887,8 +888,10 @@ public void ResetCandidateConfigFilePath() _candidateConfigFilePaths = null; } - private Logger GetLogger(LoggerCacheKey cacheKey) + private Logger GetLoggerThreadSafe(string name, Type loggerType) { + LoggerCacheKey cacheKey = new LoggerCacheKey(name, loggerType ?? typeof(Logger)); + lock (_syncRoot) { Logger existingLogger = _loggerCache.Retrieve(cacheKey); @@ -898,49 +901,44 @@ private Logger GetLogger(LoggerCacheKey cacheKey) return existingLogger; } - Logger newLogger; - if (cacheKey.ConcreteType != null && cacheKey.ConcreteType != typeof(Logger)) + Logger newLogger = CreateNewLogger(cacheKey.ConcreteType); + if (newLogger == null) { - try - { - newLogger = CreateCustomLoggerType(cacheKey.ConcreteType); - if (newLogger == null) - { - // Creating default instance of logger if instance of specified type cannot be created. - newLogger = CreateDefaultLogger(ref cacheKey); - } - } - catch (Exception ex) - { - InternalLogger.Error(ex, "GetLogger / GetCurrentClassLogger. Cannot create instance of type '{0}'. It should have an default contructor.", cacheKey.ConcreteType); + cacheKey = new LoggerCacheKey(cacheKey.Name, typeof(Logger)); + newLogger = new Logger(); + } - if (ex.MustBeRethrown()) - { - throw; - } + newLogger.Initialize(name, GetConfigurationForLogger(name, Configuration), this); + _loggerCache.InsertOrUpdate(cacheKey, newLogger); + return newLogger; + } + } - // Creating default instance of logger if instance of specified type cannot be created. - newLogger = CreateDefaultLogger(ref cacheKey); - } - } - else + internal Logger CreateNewLogger(Type loggerType) + { + Logger newLogger; + if (loggerType != null && loggerType != typeof(Logger)) + { + try { - newLogger = new Logger(); + newLogger = CreateCustomLoggerType(loggerType); } - - if (cacheKey.ConcreteType != null) + catch (Exception ex) { - newLogger.Initialize(cacheKey.Name, GetConfigurationForLogger(cacheKey.Name, Configuration), this); + InternalLogger.Error(ex, "GetLogger / GetCurrentClassLogger. Cannot create instance of type '{0}'. It should have an default contructor.", loggerType); + if (ex.MustBeRethrown()) + { + throw; + } + newLogger = null; } - - // TODO: Clarify what is the intention when cacheKey.ConcreteType = null. - // At the moment, a logger typeof(Logger) will be created but the ConcreteType - // will remain null and inserted into the cache. - // Should we set cacheKey.ConcreteType = typeof(Logger) for default loggers? - - _loggerCache.InsertOrUpdate(cacheKey, newLogger); - return newLogger; } + else + { + newLogger = new Logger(); + } + + return newLogger; } private Logger CreateCustomLoggerType(Type customLoggerType) @@ -978,14 +976,6 @@ private Logger CreateCustomLoggerType(Type customLoggerType) } } - private static Logger CreateDefaultLogger(ref LoggerCacheKey cacheKey) - { - cacheKey = new LoggerCacheKey(cacheKey.Name, typeof(Logger)); - - var newLogger = new Logger(); - return newLogger; - } - /// /// Loads logging configuration from file (Currently only XML configuration files supported) /// @@ -1004,7 +994,7 @@ public LogFactory LoadConfiguration(string configFile) /// /// Logger cache key. /// - internal struct LoggerCacheKey : IEquatable + private struct LoggerCacheKey : IEquatable { public readonly string Name; public readonly Type ConcreteType; From 91e75892cf6626af50c8c38834d7cbd1240a7fa2 Mon Sep 17 00:00:00 2001 From: "dependabot[bot]" Date: Wed, 10 Apr 2019 06:46:12 +0000 Subject: [PATCH 02/57] Bump Microsoft.Data.Sqlite from 2.2.3 to 2.2.4 in /tests/NLog.UnitTests Bumps [Microsoft.Data.Sqlite](https://github.com/aspnet/EntityFrameworkCore) from 2.2.3 to 2.2.4. - [Release notes](https://github.com/aspnet/EntityFrameworkCore/releases) - [Commits](https://github.com/aspnet/EntityFrameworkCore/commits/v2.2.4) Signed-off-by: dependabot[bot] --- tests/NLog.UnitTests/NLog.UnitTests.csproj | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/tests/NLog.UnitTests/NLog.UnitTests.csproj b/tests/NLog.UnitTests/NLog.UnitTests.csproj index ed53c99d29..cc149b735e 100644 --- a/tests/NLog.UnitTests/NLog.UnitTests.csproj +++ b/tests/NLog.UnitTests/NLog.UnitTests.csproj @@ -54,7 +54,7 @@ - + From 701dfdd7bec24849df4d9317b08b37e79d225351 Mon Sep 17 00:00:00 2001 From: Rolf Kristensen Date: Wed, 10 Apr 2019 22:39:48 +0200 Subject: [PATCH 03/57] AsyncTaskTarget_TestThrottleOnTaskDelay - More waiting for timers added --- tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs b/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs index c42635cb92..ec6e7a44ff 100644 --- a/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs +++ b/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs @@ -379,14 +379,16 @@ public void AsyncTaskTarget_TestThrottleOnTaskDelay() SimpleConfigurator.ConfigureForTargetLogging(asyncTarget, LogLevel.Trace); - for (int i = 0; i < 50; ++i) + for (int i = 0; i < 5; ++i) { - logger.Log(LogLevel.Info, i.ToString()); - Thread.Sleep(20); + for (int j = 0; j < 10; ++j) + { + logger.Log(LogLevel.Info, i.ToString()); + Thread.Sleep(20); + } + Assert.True(asyncTarget.WaitForWriteEvent(0)); } - Assert.True(asyncTarget.WaitForWriteEvent(0)); - Assert.True(asyncTarget.Logs.Count > 25, $"{asyncTarget.Logs.Count} LogEvents are too few after {asyncTarget.WriteTasks} writes"); Assert.True(asyncTarget.WriteTasks < 20, $"{asyncTarget.WriteTasks} writes are too many."); } From 47f861dc8a406075b1abde460d00ac033d28c937 Mon Sep 17 00:00:00 2001 From: Rolf Kristensen Date: Wed, 10 Apr 2019 22:31:08 +0200 Subject: [PATCH 04/57] Logger - WithProperty for adding Logger specific properties that are included for all LogEvents --- src/NLog/Internal/LoggerConfiguration.cs | 16 --- src/NLog/LogFactory.cs | 3 +- src/NLog/Logger-generated.cs | 12 +- src/NLog/Logger-generated.tt | 4 +- src/NLog/Logger.cs | 157 ++++++++++++++++------- src/NLog/LoggerImpl.cs | 13 +- tests/NLog.UnitTests/LoggerTests.cs | 57 ++++++++ 7 files changed, 180 insertions(+), 82 deletions(-) diff --git a/src/NLog/Internal/LoggerConfiguration.cs b/src/NLog/Internal/LoggerConfiguration.cs index 9bda807691..919eacbeef 100644 --- a/src/NLog/Internal/LoggerConfiguration.cs +++ b/src/NLog/Internal/LoggerConfiguration.cs @@ -75,21 +75,5 @@ public TargetWithFilterChain GetTargetsForLevel(LogLevel level) } return _targetsByLevel[level.Ordinal]; } - - /// - /// Determines whether the specified level is enabled. - /// - /// The level. - /// - /// A value of true if the specified level is enabled; otherwise, false. - /// - public bool IsEnabled(LogLevel level) - { - if (level == LogLevel.Off) - { - return false; - } - return _targetsByLevel[level.Ordinal] != null; - } } } diff --git a/src/NLog/LogFactory.cs b/src/NLog/LogFactory.cs index 92064d2a44..f4acd65449 100644 --- a/src/NLog/LogFactory.cs +++ b/src/NLog/LogFactory.cs @@ -392,7 +392,7 @@ public Logger GetCurrentClassLogger(Type loggerType) /// are not guaranteed to return the same logger reference. public Logger GetLogger(string name) { - return GetLoggerThreadSafe(name, typeof(Logger)); + return GetLoggerThreadSafe(name, Logger.DefaultLoggerType); } /// @@ -431,7 +431,6 @@ public void ReconfigExistingLoggers() lock (_syncRoot) { _config?.InitializeAll(); - loggers = _loggerCache.GetLoggers(); } diff --git a/src/NLog/Logger-generated.cs b/src/NLog/Logger-generated.cs index dca69f96fc..f177e21523 100644 --- a/src/NLog/Logger-generated.cs +++ b/src/NLog/Logger-generated.cs @@ -48,7 +48,7 @@ public partial class Logger /// A value of if logging is enabled for the Trace level, otherwise it returns . public bool IsTraceEnabled { - get { return _isTraceEnabled; } + get { return _contextLogger._isTraceEnabled; } } /// @@ -57,7 +57,7 @@ public bool IsTraceEnabled /// A value of if logging is enabled for the Debug level, otherwise it returns . public bool IsDebugEnabled { - get { return _isDebugEnabled; } + get { return _contextLogger._isDebugEnabled; } } /// @@ -66,7 +66,7 @@ public bool IsDebugEnabled /// A value of if logging is enabled for the Info level, otherwise it returns . public bool IsInfoEnabled { - get { return _isInfoEnabled; } + get { return _contextLogger._isInfoEnabled; } } /// @@ -75,7 +75,7 @@ public bool IsInfoEnabled /// A value of if logging is enabled for the Warn level, otherwise it returns . public bool IsWarnEnabled { - get { return _isWarnEnabled; } + get { return _contextLogger._isWarnEnabled; } } /// @@ -84,7 +84,7 @@ public bool IsWarnEnabled /// A value of if logging is enabled for the Error level, otherwise it returns . public bool IsErrorEnabled { - get { return _isErrorEnabled; } + get { return _contextLogger._isErrorEnabled; } } /// @@ -93,7 +93,7 @@ public bool IsErrorEnabled /// A value of if logging is enabled for the Fatal level, otherwise it returns . public bool IsFatalEnabled { - get { return _isFatalEnabled; } + get { return _contextLogger._isFatalEnabled; } } diff --git a/src/NLog/Logger-generated.tt b/src/NLog/Logger-generated.tt index 8d5ed2e236..6d0f28b191 100644 --- a/src/NLog/Logger-generated.tt +++ b/src/NLog/Logger-generated.tt @@ -55,7 +55,7 @@ namespace NLog var levels = new string[]{"Trace", "Debug", "Info", "Warn", "Error", "Fatal"}; foreach(var level in levels) - { + { #> /// /// Gets a value indicating whether logging is enabled for the <#=level#> level. @@ -63,7 +63,7 @@ namespace NLog /// A value of if logging is enabled for the <#=level#> level, otherwise it returns . public bool Is<#=level#>Enabled { - get { return _is<#=level#>Enabled; } + get { return _contextLogger._is<#=level#>Enabled; } } <# diff --git a/src/NLog/Logger.cs b/src/NLog/Logger.cs index 2537904d2a..96c7c77867 100644 --- a/src/NLog/Logger.cs +++ b/src/NLog/Logger.cs @@ -34,12 +34,13 @@ namespace NLog { using System; + using System.Collections.Generic; using System.ComponentModel; - using NLog.Internal; - #if NET4_5 using System.Threading.Tasks; #endif + using JetBrains.Annotations; + using NLog.Internal; /// /// Provides logging interface and utility functions. @@ -47,9 +48,10 @@ namespace NLog [CLSCompliant(true)] public partial class Logger : ILogger { - private readonly Type _loggerType = typeof(Logger); - - private volatile LoggerConfiguration _configuration; + internal static readonly Type DefaultLoggerType = typeof(Logger); + private Logger _contextLogger; + private Dictionary _contextProperties; + private LoggerConfiguration _configuration; private volatile bool _isTraceEnabled; private volatile bool _isDebugEnabled; private volatile bool _isInfoEnabled; @@ -62,6 +64,35 @@ public partial class Logger : ILogger /// protected internal Logger() { + _contextLogger = this; + } + + /// + /// Creates new logger that automatically appends the specified property to all log events + /// + /// Property Name + /// Property Value + /// New Logger that automatically appends specified property + public Logger WithProperty(string propertyKey, object propertyValue) + { + if (string.IsNullOrEmpty(propertyKey)) + throw new ArgumentException(nameof(propertyKey)); + + Logger newLogger = Factory.CreateNewLogger(GetType()) ?? new Logger(); + newLogger.Initialize(Name, _configuration, Factory); + var contextProperties = _contextProperties != null + ? new Dictionary(_contextProperties) + : new Dictionary(); + contextProperties[propertyKey] = propertyValue; + newLogger._contextProperties = contextProperties; + newLogger._contextLogger = _contextLogger; + newLogger._isTraceEnabled = true; + newLogger._isDebugEnabled = true; + newLogger._isInfoEnabled = true; + newLogger._isWarnEnabled = true; + newLogger._isErrorEnabled = true; + newLogger._isFatalEnabled = true; + return newLogger; } /// @@ -100,11 +131,12 @@ public bool IsEnabled(LogLevel level) /// Log event. public void Log(LogEventInfo logEvent) { - if (IsEnabled(logEvent.Level)) + var targetsForLevel = IsEnabled(logEvent.Level) ? GetTargetsForLevel(logEvent.Level) : null; + if (targetsForLevel != null) { if (logEvent.LoggerName == null) logEvent.LoggerName = Name; - WriteToTargets(logEvent); + WriteToTargets(logEvent, targetsForLevel); } } @@ -115,11 +147,12 @@ public void Log(LogEventInfo logEvent) /// Log event. public void Log(Type wrapperType, LogEventInfo logEvent) { - if (IsEnabled(logEvent.Level)) + var targetsForLevel = IsEnabled(logEvent.Level) ? GetTargetsForLevel(logEvent.Level) : null; + if (targetsForLevel != null) { if (logEvent.LoggerName == null) logEvent.LoggerName = Name; - WriteToTargets(wrapperType, logEvent); + WriteToTargets(wrapperType, logEvent, targetsForLevel); } } @@ -392,25 +425,23 @@ public void Log(LogLevel level, [Localizable(false)] string message, } } - private void WriteToTargets(LogLevel level, Exception ex, [Localizable(false)] string message, object[] args) - { - LoggerImpl.Write(_loggerType, GetTargetsForLevel(level), PrepareLogEventInfo(LogEventInfo.Create(level, Name, ex, Factory.DefaultCultureInfo, message, args)), Factory); - } - - private void WriteToTargets(LogLevel level, Exception ex, IFormatProvider formatProvider, [Localizable(false)] string message, object[] args) - { - LoggerImpl.Write(_loggerType, GetTargetsForLevel(level), PrepareLogEventInfo(LogEventInfo.Create(level, Name, ex, formatProvider, message, args)), Factory); - } - - private LogEventInfo PrepareLogEventInfo(LogEventInfo logEvent) { if (logEvent.FormatProvider == null) { logEvent.FormatProvider = Factory.DefaultCultureInfo; } + if (_contextProperties != null) + { + foreach (var property in _contextProperties) + { + if (!logEvent.Properties.ContainsKey(property.Key)) + { + logEvent.Properties[property.Key] = property.Value; + } + } + } return logEvent; - } #endregion @@ -557,38 +588,71 @@ internal void Initialize(string name, LoggerConfiguration loggerConfiguration, L SetConfiguration(loggerConfiguration); } - internal void WriteToTargets(LogLevel level, IFormatProvider formatProvider, [Localizable(false)] string message, object[] args) + private void WriteToTargets(LogLevel level, [Localizable(false)] string message, object[] args) + { + WriteToTargets(level, Factory.DefaultCultureInfo, message, args); + } + + private void WriteToTargets(LogLevel level, IFormatProvider formatProvider, [Localizable(false)] string message, object[] args) { - LoggerImpl.Write(_loggerType, GetTargetsForLevel(level), PrepareLogEventInfo(LogEventInfo.Create(level, Name, formatProvider, message, args)), Factory); + var targetsForLevel = GetTargetsForLevel(level); + if (targetsForLevel != null) + { + var logEvent = LogEventInfo.Create(level, Name, formatProvider, message, args); + WriteToTargets(logEvent, targetsForLevel); + } } private void WriteToTargets(LogLevel level, IFormatProvider formatProvider, [Localizable(false)] string message) { - // please note that this overload calls the overload of LogEventInfo.Create with object[] parameter on purpose - - // to avoid unnecessary string.Format (in case of calling Create(LogLevel, string, IFormatProvider, object)) - var logEvent = LogEventInfo.Create(level, Name, formatProvider, message, (object[])null); - LoggerImpl.Write(_loggerType, GetTargetsForLevel(level), PrepareLogEventInfo(logEvent), Factory); + var targetsForLevel = GetTargetsForLevel(level); + if (targetsForLevel != null) + { + // please note that this overload calls the overload of LogEventInfo.Create with object[] parameter on purpose - + // to avoid unnecessary string.Format (in case of calling Create(LogLevel, string, IFormatProvider, object)) + var logEvent = LogEventInfo.Create(level, Name, formatProvider, message, (object[])null); + WriteToTargets(logEvent, targetsForLevel); + } } private void WriteToTargets(LogLevel level, IFormatProvider formatProvider, T value) { - var logEvent = PrepareLogEventInfo(LogEventInfo.Create(level, Name, formatProvider, value)); - LoggerImpl.Write(_loggerType, GetTargetsForLevel(level), logEvent, Factory); + var targetsForLevel = GetTargetsForLevel(level); + if (targetsForLevel != null) + { + var logEvent = LogEventInfo.Create(level, Name, formatProvider, value); + WriteToTargets(logEvent, targetsForLevel); + } } - internal void WriteToTargets(LogLevel level, [Localizable(false)] string message, object[] args) + private void WriteToTargets(LogLevel level, Exception ex, [Localizable(false)] string message, object[] args) { - WriteToTargets(level, Factory.DefaultCultureInfo, message, args); + var targetsForLevel = GetTargetsForLevel(level); + if (targetsForLevel != null) + { + var logEvent = LogEventInfo.Create(level, Name, ex, Factory.DefaultCultureInfo, message, args); + WriteToTargets(logEvent, targetsForLevel); + } } - private void WriteToTargets(LogEventInfo logEvent) + private void WriteToTargets(LogLevel level, Exception ex, IFormatProvider formatProvider, [Localizable(false)] string message, object[] args) { - LoggerImpl.Write(_loggerType, GetTargetsForLevel(logEvent.Level), PrepareLogEventInfo(logEvent), Factory); + var targetsForLevel = GetTargetsForLevel(level); + if (targetsForLevel != null) + { + var logEvent = LogEventInfo.Create(level, Name, ex, formatProvider, message, args); + WriteToTargets(logEvent, targetsForLevel); + } } - private void WriteToTargets(Type wrapperType, LogEventInfo logEvent) + private void WriteToTargets([NotNull] LogEventInfo logEvent, [NotNull] TargetWithFilterChain targetsForLevel) { - LoggerImpl.Write(wrapperType ?? _loggerType, GetTargetsForLevel(logEvent.Level), PrepareLogEventInfo(logEvent), Factory); + LoggerImpl.Write(DefaultLoggerType, targetsForLevel, PrepareLogEventInfo(logEvent), Factory); + } + + private void WriteToTargets(Type wrapperType, [NotNull] LogEventInfo logEvent, [NotNull] TargetWithFilterChain targetsForLevel) + { + LoggerImpl.Write(wrapperType ?? DefaultLoggerType, targetsForLevel, PrepareLogEventInfo(logEvent), Factory); } internal void SetConfiguration(LoggerConfiguration newConfiguration) @@ -596,19 +660,22 @@ internal void SetConfiguration(LoggerConfiguration newConfiguration) _configuration = newConfiguration; // pre-calculate 'enabled' flags - _isTraceEnabled = newConfiguration.IsEnabled(LogLevel.Trace); - _isDebugEnabled = newConfiguration.IsEnabled(LogLevel.Debug); - _isInfoEnabled = newConfiguration.IsEnabled(LogLevel.Info); - _isWarnEnabled = newConfiguration.IsEnabled(LogLevel.Warn); - _isErrorEnabled = newConfiguration.IsEnabled(LogLevel.Error); - _isFatalEnabled = newConfiguration.IsEnabled(LogLevel.Fatal); + _isTraceEnabled = IsEnabled(LogLevel.Trace); + _isDebugEnabled = IsEnabled(LogLevel.Debug); + _isInfoEnabled = IsEnabled(LogLevel.Info); + _isWarnEnabled = IsEnabled(LogLevel.Warn); + _isErrorEnabled = IsEnabled(LogLevel.Error); + _isFatalEnabled = IsEnabled(LogLevel.Fatal); OnLoggerReconfigured(EventArgs.Empty); } private TargetWithFilterChain GetTargetsForLevel(LogLevel level) { - return _configuration.GetTargetsForLevel(level); + if (ReferenceEquals(_contextLogger, this)) + return _configuration.GetTargetsForLevel(level); + else + return _contextLogger.GetTargetsForLevel(level); } /// @@ -617,11 +684,7 @@ private TargetWithFilterChain GetTargetsForLevel(LogLevel level) /// Event arguments protected virtual void OnLoggerReconfigured(EventArgs e) { - var reconfigured = LoggerReconfigured; - if (reconfigured != null) - { - reconfigured(this, e); - } + LoggerReconfigured?.Invoke(this, e); } } } diff --git a/src/NLog/LoggerImpl.cs b/src/NLog/LoggerImpl.cs index 99debbfe4d..21d4a1e886 100644 --- a/src/NLog/LoggerImpl.cs +++ b/src/NLog/LoggerImpl.cs @@ -51,15 +51,10 @@ internal static class LoggerImpl private const int StackTraceSkipMethods = 0; [System.Diagnostics.CodeAnalysis.SuppressMessage("Microsoft.Naming", "CA2204:Literals should be spelled correctly", Justification = "Using 'NLog' in message.")] - internal static void Write([NotNull] Type loggerType, TargetWithFilterChain targets, LogEventInfo logEvent, LogFactory factory) + internal static void Write([NotNull] Type loggerType, [NotNull] TargetWithFilterChain targetsForLevel, LogEventInfo logEvent, LogFactory factory) { - if (targets == null) - { - return; - } - #if !NETSTANDARD1_0 || NETSTANDARD1_5 - StackTraceUsage stu = targets.GetStackTraceUsage(); + StackTraceUsage stu = targetsForLevel.GetStackTraceUsage(); if (stu != StackTraceUsage.None && !logEvent.HasStackTrace) { #if NETSTANDARD1_5 @@ -89,7 +84,7 @@ internal static void Write([NotNull] Type loggerType, TargetWithFilterChain targ }; } - if (targets.NextInChain == null && logEvent.CanLogEventDeferMessageFormat()) + if (targetsForLevel.NextInChain == null && logEvent.CanLogEventDeferMessageFormat()) { // Change MessageFormatter so it writes directly to StringBuilder without string-allocation logEvent.MessageFormatter = LogMessageTemplateFormatter.DefaultAutoSingleTarget.MessageFormatter; @@ -97,7 +92,7 @@ internal static void Write([NotNull] Type loggerType, TargetWithFilterChain targ IList prevFilterChain = null; FilterResult prevFilterResult = FilterResult.Neutral; - for (var t = targets; t != null; t = t.NextInChain) + for (var t = targetsForLevel; t != null; t = t.NextInChain) { FilterResult result = ReferenceEquals(prevFilterChain, t.FilterChain) ? prevFilterResult : GetFilterResult(t.FilterChain, logEvent, t.DefaultResult); diff --git a/tests/NLog.UnitTests/LoggerTests.cs b/tests/NLog.UnitTests/LoggerTests.cs index c4d63a18d5..89788e7c53 100644 --- a/tests/NLog.UnitTests/LoggerTests.cs +++ b/tests/NLog.UnitTests/LoggerTests.cs @@ -2390,5 +2390,62 @@ public void LogEventTemplateShouldHaveProperties_even_when_changed() Assert.Equal("b", props["A"]); Assert.Equal(1, props.Count); } + + static Logger GetContextLoggerFromTemporary(string loggerName) + { + var loggerRaw = LogManager.GetLogger(loggerName); + var loggerStage1 = loggerRaw.WithProperty("Stage", 1); + loggerRaw.Trace("{Stage}", "Connected"); + return loggerStage1; + } + + [Fact] + public void LogEventTemplateShouldOverrideProperties() + { + string uniqueLoggerName = Guid.NewGuid().ToString(); + + var config = new LoggingConfiguration(); + var target = new MyTarget(); + config.LoggingRules.Add(new LoggingRule(uniqueLoggerName, LogLevel.Trace, target)); + LogManager.Configuration = config; + Logger loggerStage1 = GetContextLoggerFromTemporary(uniqueLoggerName); + GC.Collect(); // Try and free loggerRaw + var loggerStage2 = loggerStage1.WithProperty("Stage", 2); + Assert.Single(target.LastEvent.Properties); + AssertContainsInDictionary(target.LastEvent.Properties, "Stage", "Connected"); + loggerStage1.Trace("Login attempt from {userid}", "kermit"); + Assert.Equal(2, target.LastEvent.Properties.Count); + AssertContainsInDictionary(target.LastEvent.Properties, "Stage", 1); + AssertContainsInDictionary(target.LastEvent.Properties, "userid", "kermit"); + loggerStage2.Trace("Login succesful for {userid}", "kermit"); + Assert.Equal(2, target.LastEvent.Properties.Count); + AssertContainsInDictionary(target.LastEvent.Properties, "Stage", 2); + AssertContainsInDictionary(target.LastEvent.Properties, "userid", "kermit"); + loggerStage2.Trace("{Stage}", "Disconnected"); + Assert.Single(target.LastEvent.Properties); + AssertContainsInDictionary(target.LastEvent.Properties, "Stage", "Disconnected"); + } + + [Fact] + public void LoggerWithPropertyShouldInheritLogLevel() + { + string uniqueLoggerName = Guid.NewGuid().ToString(); + + var config = new LoggingConfiguration(); + var target = new MyTarget(); + config.LoggingRules.Add(new LoggingRule(uniqueLoggerName, LogLevel.Trace, target)); + LogManager.Configuration = config; + Logger loggerStage1 = GetContextLoggerFromTemporary(uniqueLoggerName); + GC.Collect(); // Try and free loggerRaw + Assert.Single(target.LastEvent.Properties); + AssertContainsInDictionary(target.LastEvent.Properties, "Stage", "Connected"); + LogManager.Configuration.LoggingRules[0].DisableLoggingForLevel(LogLevel.Trace); + LogManager.ReconfigExistingLoggers(); // Refreshes the configuration of loggerRaw + var loggerStage2 = loggerStage1.WithProperty("Stage", 2); + loggerStage2.Trace("Login attempt from {userid}", "kermit"); + AssertContainsInDictionary(target.LastEvent.Properties, "Stage", "Connected"); // Verify nothing writtne + loggerStage2.Debug("{Stage}", "Disconnected"); + AssertContainsInDictionary(target.LastEvent.Properties, "Stage", "Disconnected"); + } } } From 1e7e12163fd79838b6b82c889a6453419ba918d9 Mon Sep 17 00:00:00 2001 From: Rolf Kristensen Date: Sun, 14 Apr 2019 10:22:36 +0200 Subject: [PATCH 05/57] XmlLoggingConfiguration - Respect KeepVariablesOnReload for manual reload --- src/NLog/Config/LoggingConfiguration.cs | 25 +++++++++++++++++++ ...LoggingConfigurationWatchableFileLoader.cs | 7 +----- tests/NLog.UnitTests/Config/ReloadTests.cs | 9 +++++++ 3 files changed, 35 insertions(+), 6 deletions(-) diff --git a/src/NLog/Config/LoggingConfiguration.cs b/src/NLog/Config/LoggingConfiguration.cs index 0c91d3844c..425deb1e54 100644 --- a/src/NLog/Config/LoggingConfiguration.cs +++ b/src/NLog/Config/LoggingConfiguration.cs @@ -482,6 +482,31 @@ public virtual LoggingConfiguration Reload() return this; } + /// + /// Helper method to perform correct reload of log configuration with respect to + /// + /// Current Configuration + /// + /// A new instance of that represents the updated configuration. + /// + public static LoggingConfiguration Reload(LoggingConfiguration oldConfig) + { + var newConfig = oldConfig?.Reload(); + if (newConfig != null) + { + var logFactory = oldConfig.LogFactory ?? LogManager.LogFactory; + if (logFactory.KeepVariablesOnReload) + { + var currentConfig = logFactory._config ?? oldConfig; + if (!ReferenceEquals(newConfig, currentConfig)) + { + newConfig.CopyVariables(currentConfig.Variables); + } + } + } + return newConfig; + } + /// /// Removes the specified named target. /// diff --git a/src/NLog/Config/LoggingConfigurationWatchableFileLoader.cs b/src/NLog/Config/LoggingConfigurationWatchableFileLoader.cs index 38324f7c50..a1e8b8073d 100644 --- a/src/NLog/Config/LoggingConfigurationWatchableFileLoader.cs +++ b/src/NLog/Config/LoggingConfigurationWatchableFileLoader.cs @@ -156,7 +156,7 @@ internal void ReloadConfigOnTimer(object state) return; } - newConfig = oldConfig.Reload(); + newConfig = LoggingConfiguration.Reload(oldConfig); //problem: XmlLoggingConfiguration.Initialize eats exception with invalid XML. ALso XmlLoggingConfiguration.Reload never returns null. //therefor we check the InitializeSucceeded property. @@ -185,11 +185,6 @@ internal void ReloadConfigOnTimer(object state) if (newConfig != null) { - if (_logFactory.KeepVariablesOnReload && _logFactory._config != null) - { - newConfig.CopyVariables(_logFactory._config.Variables); - } - _logFactory.Configuration = newConfig; // Triggers LogFactory to call Activated(...) that adds file-watch again _logFactory?.NotifyConfigurationReloaded(new LoggingConfigurationReloadedEventArgs(true)); diff --git a/tests/NLog.UnitTests/Config/ReloadTests.cs b/tests/NLog.UnitTests/Config/ReloadTests.cs index d6c1fc4cf9..722d6bd00c 100644 --- a/tests/NLog.UnitTests/Config/ReloadTests.cs +++ b/tests/NLog.UnitTests/Config/ReloadTests.cs @@ -583,6 +583,11 @@ public void TestKeepVariablesOnReload() Assert.Equal("new_value", logFactory.Configuration.Variables["var1"].OriginalText); Assert.Equal("keep_value", logFactory.Configuration.Variables["var2"].OriginalText); Assert.Equal("new_value3", logFactory.Configuration.Variables["var3"].OriginalText); + + logFactory.Configuration = LoggingConfiguration.Reload(configuration); + Assert.Equal("new_value", logFactory.Configuration.Variables["var1"].OriginalText); + Assert.Equal("keep_value", logFactory.Configuration.Variables["var2"].OriginalText); + Assert.Equal("new_value3", logFactory.Configuration.Variables["var3"].OriginalText); } [Fact] @@ -602,6 +607,10 @@ public void TestResetVariablesOnReload() configLoader.ReloadConfigOnTimer(configuration); Assert.Equal("", logFactory.Configuration.Variables["var1"].OriginalText); Assert.Equal("keep_value", logFactory.Configuration.Variables["var2"].OriginalText); + + logFactory.Configuration = LoggingConfiguration.Reload(configuration); + Assert.Equal("", logFactory.Configuration.Variables["var1"].OriginalText); + Assert.Equal("keep_value", logFactory.Configuration.Variables["var2"].OriginalText); } [Fact] From ce815cf8d131ca19720d0d69f4979f7649fad7cc Mon Sep 17 00:00:00 2001 From: Rolf Kristensen Date: Sun, 14 Apr 2019 13:41:42 +0200 Subject: [PATCH 06/57] AsyncTaskTarget_TestThrottleOnTaskDelay - Changed to ConcurrentQueue (#3307) --- .../Targets/AsyncTaskTargetTest.cs | 30 ++++++++----------- 1 file changed, 12 insertions(+), 18 deletions(-) diff --git a/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs b/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs index ec6e7a44ff..b989df855c 100644 --- a/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs +++ b/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs @@ -35,19 +35,20 @@ namespace NLog.UnitTests.Targets { #if !NET3_5 using System; + using System.Collections.Concurrent; using System.Collections.Generic; using System.Threading; using System.Threading.Tasks; - using Xunit; using NLog.Config; using NLog.Targets; + using Xunit; public class AsyncTaskTargetTest : NLogTestBase { class AsyncTaskTestTarget : AsyncTaskTarget { private readonly AutoResetEvent _writeEvent = new AutoResetEvent(false); - internal readonly Queue Logs = new Queue(); + internal readonly ConcurrentQueue Logs = new ConcurrentQueue(); internal int WriteTasks => _writeTasks; protected int _writeTasks; @@ -120,9 +121,8 @@ public void AsyncTaskTarget_TestLogging() Assert.NotEmpty(asyncTarget.Logs); LogManager.Flush(); Assert.True(asyncTarget.Logs.Count == 6); - while (asyncTarget.Logs.Count > 0) + while (asyncTarget.Logs.TryDequeue(out var logEventMessage)) { - string logEventMessage = asyncTarget.Logs.Dequeue(); Assert.Equal(0, logEventMessage.IndexOf(Thread.CurrentThread.ManagedThreadId.ToString() + "|")); } @@ -150,9 +150,8 @@ public void AsyncTaskTarget_TestAsyncException() Assert.Equal(LogLevel.MaxLevel.Ordinal, asyncTarget.Logs.Count); int ordinal = 0; - while (asyncTarget.Logs.Count > 0) + while (asyncTarget.Logs.TryDequeue(out var logEventMessage)) { - string logEventMessage = asyncTarget.Logs.Dequeue(); var logLevel = LogLevel.FromString(logEventMessage); Assert.NotEqual(LogLevel.Debug, logLevel); Assert.Equal(ordinal++, logLevel.Ordinal); @@ -187,10 +186,9 @@ public void AsyncTaskTarget_TestTimeout() Assert.True(asyncTarget.WaitForWriteEvent()); Assert.NotEmpty(asyncTarget.Logs); LogManager.Flush(); - Assert.True(asyncTarget.Logs.Count == 5); - while (asyncTarget.Logs.Count > 0) + Assert.Equal(5, asyncTarget.Logs.Count); + while (asyncTarget.Logs.TryDequeue(out var logEventMessage)) { - string logEventMessage = asyncTarget.Logs.Dequeue(); Assert.Equal(-1, logEventMessage.IndexOf("Debug|")); } @@ -221,9 +219,8 @@ public void AsyncTaskTarget_TestRetryAsyncException() Assert.Equal(LogLevel.MaxLevel.Ordinal + 4, asyncTarget.WriteTasks); int ordinal = 0; - while (asyncTarget.Logs.Count > 0) + while (asyncTarget.Logs.TryDequeue(out var logEventMessage)) { - string logEventMessage = asyncTarget.Logs.Dequeue(); var logLevel = LogLevel.FromString(logEventMessage); Assert.NotEqual(LogLevel.Debug, logLevel); Assert.Equal(ordinal++, logLevel.Ordinal); @@ -257,9 +254,8 @@ public void AsyncTaskTarget_TestRetryException() Assert.Equal(LogLevel.MaxLevel.Ordinal + 4, asyncTarget.WriteTasks); int ordinal = 0; - while (asyncTarget.Logs.Count > 0) + while (asyncTarget.Logs.TryDequeue(out var logEventMessage)) { - string logEventMessage = asyncTarget.Logs.Dequeue(); var logLevel = LogLevel.FromString(logEventMessage); Assert.NotEqual(LogLevel.Debug, logLevel); Assert.Equal(ordinal++, logLevel.Ordinal); @@ -293,9 +289,8 @@ public void AsyncTaskTarget_TestBatchWriting() Assert.Equal(LogLevel.MaxLevel.Ordinal / 2, asyncTarget.WriteTasks); int ordinal = 0; - while (asyncTarget.Logs.Count > 0) + while (asyncTarget.Logs.TryDequeue(out var logEventMessage)) { - string logEventMessage = asyncTarget.Logs.Dequeue(); var logLevel = LogLevel.FromString(logEventMessage); Assert.Equal(ordinal++, logLevel.Ordinal); } @@ -327,9 +322,8 @@ public void AsyncTaskTarget_TestFakeBatchWriting() Assert.Equal(LogLevel.MaxLevel.Ordinal + 1, asyncTarget.WriteTasks); int ordinal = 0; - while (asyncTarget.Logs.Count > 0) + while (asyncTarget.Logs.TryDequeue(out var logEventMessage)) { - string logEventMessage = asyncTarget.Logs.Dequeue(); var logLevel = LogLevel.FromString(logEventMessage); Assert.Equal(ordinal++, logLevel.Ordinal); } @@ -386,7 +380,7 @@ public void AsyncTaskTarget_TestThrottleOnTaskDelay() logger.Log(LogLevel.Info, i.ToString()); Thread.Sleep(20); } - Assert.True(asyncTarget.WaitForWriteEvent(0)); + Assert.True(asyncTarget.WaitForWriteEvent()); } Assert.True(asyncTarget.Logs.Count > 25, $"{asyncTarget.Logs.Count} LogEvents are too few after {asyncTarget.WriteTasks} writes"); From 2879cc9433f2597ba243ab2694e3f1ffd28d629b Mon Sep 17 00:00:00 2001 From: Rolf Kristensen Date: Sun, 14 Apr 2019 18:47:03 +0200 Subject: [PATCH 07/57] AsyncTaskTarget_TestLogging - Include MDLC test --- .../Targets/AsyncTaskTargetTest.cs | 29 +++++++++++++------ 1 file changed, 20 insertions(+), 9 deletions(-) diff --git a/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs b/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs index b989df855c..77f91eb5b8 100644 --- a/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs +++ b/tests/NLog.UnitTests/Targets/AsyncTaskTargetTest.cs @@ -106,24 +106,35 @@ public void AsyncTaskTarget_TestLogging() { ILogger logger = LogManager.GetCurrentClassLogger(); - var asyncTarget = new AsyncTaskTestTarget { Layout = "${threadid}|${level}|${message}" }; + var asyncTarget = new AsyncTaskTestTarget { Layout = "${threadid}|${level}|${message}|${mdlc:item=Test}" }; SimpleConfigurator.ConfigureForTargetLogging(asyncTarget, LogLevel.Trace); NLog.Common.InternalLogger.LogLevel = LogLevel.Off; - logger.Trace("TTT"); - logger.Debug("DDD"); - logger.Info("III"); - logger.Warn("WWW"); - logger.Error("EEE"); - logger.Fatal("FFF"); + int managedThreadId = 0; + Task task; + using (MappedDiagnosticsLogicalContext.SetScoped("Test", 42)) + { + task = Task.Run(() => + { + managedThreadId = Thread.CurrentThread.ManagedThreadId; + logger.Trace("TTT"); + logger.Debug("DDD"); + logger.Info("III"); + logger.Warn("WWW"); + logger.Error("EEE"); + logger.Fatal("FFF"); + }); + } Assert.True(asyncTarget.WaitForWriteEvent()); Assert.NotEmpty(asyncTarget.Logs); + task.Wait(); LogManager.Flush(); - Assert.True(asyncTarget.Logs.Count == 6); + Assert.Equal(6, asyncTarget.Logs.Count); while (asyncTarget.Logs.TryDequeue(out var logEventMessage)) { - Assert.Equal(0, logEventMessage.IndexOf(Thread.CurrentThread.ManagedThreadId.ToString() + "|")); + Assert.Equal(0, logEventMessage.IndexOf(managedThreadId.ToString() + "|")); + Assert.EndsWith("|42", logEventMessage); } LogManager.Configuration = null; From 72b9abab7f5d58218f98f783c669dc99aae5868e Mon Sep 17 00:00:00 2001 From: Julian Verdurmen <304NotModified@users.noreply.github.com> Date: Sun, 14 Apr 2019 20:36:52 +0200 Subject: [PATCH 08/57] Refactor ParseAttributes For Sonar warning --- src/NLog/Config/NLogXmlElement.cs | 23 ++++++++++++++++------- 1 file changed, 16 insertions(+), 7 deletions(-) diff --git a/src/NLog/Config/NLogXmlElement.cs b/src/NLog/Config/NLogXmlElement.cs index c2da7b4f98..2c224bb06f 100644 --- a/src/NLog/Config/NLogXmlElement.cs +++ b/src/NLog/Config/NLogXmlElement.cs @@ -239,14 +239,9 @@ private void ParseAttributes(XmlReader reader, bool nestedElement) { do { - if (!nestedElement) + if (!nestedElement && IsSpecialXmlAttribute(reader)) { - if (reader.LocalName?.Equals("xmlns", StringComparison.OrdinalIgnoreCase) == true) - continue; - if (reader.Prefix?.Equals("xsi", StringComparison.OrdinalIgnoreCase) == true) - continue; - if (reader.Prefix?.Equals("xmlns", StringComparison.OrdinalIgnoreCase) == true) - continue; + continue; } if (!AttributeValues.ContainsKey(reader.LocalName)) @@ -263,5 +258,19 @@ private void ParseAttributes(XmlReader reader, bool nestedElement) reader.MoveToElement(); } } + + /// + /// Special attribute we could ignore + /// + private static bool IsSpecialXmlAttribute(XmlReader reader) + { + if (reader.LocalName?.Equals("xmlns", StringComparison.OrdinalIgnoreCase) == true) + return true; + if (reader.Prefix?.Equals("xsi", StringComparison.OrdinalIgnoreCase) == true) + return true; + if (reader.Prefix?.Equals("xmlns", StringComparison.OrdinalIgnoreCase) == true) + return true; + return false; + } } } \ No newline at end of file From 7585208fbe71332e8ef073af331d3f7cd27897f7 Mon Sep 17 00:00:00 2001 From: Rolf Kristensen Date: Sun, 14 Apr 2019 19:37:51 +0200 Subject: [PATCH 09/57] Logger - SetProperty for updating the current Logger object instance --- src/NLog/Logger.cs | 74 ++++++++++++++++++----------- tests/NLog.UnitTests/LoggerTests.cs | 36 +++++++++++--- 2 files changed, 75 insertions(+), 35 deletions(-) diff --git a/src/NLog/Logger.cs b/src/NLog/Logger.cs index 96c7c77867..4f4a693d29 100644 --- a/src/NLog/Logger.cs +++ b/src/NLog/Logger.cs @@ -67,34 +67,6 @@ protected internal Logger() _contextLogger = this; } - /// - /// Creates new logger that automatically appends the specified property to all log events - /// - /// Property Name - /// Property Value - /// New Logger that automatically appends specified property - public Logger WithProperty(string propertyKey, object propertyValue) - { - if (string.IsNullOrEmpty(propertyKey)) - throw new ArgumentException(nameof(propertyKey)); - - Logger newLogger = Factory.CreateNewLogger(GetType()) ?? new Logger(); - newLogger.Initialize(Name, _configuration, Factory); - var contextProperties = _contextProperties != null - ? new Dictionary(_contextProperties) - : new Dictionary(); - contextProperties[propertyKey] = propertyValue; - newLogger._contextProperties = contextProperties; - newLogger._contextLogger = _contextLogger; - newLogger._isTraceEnabled = true; - newLogger._isDebugEnabled = true; - newLogger._isInfoEnabled = true; - newLogger._isWarnEnabled = true; - newLogger._isErrorEnabled = true; - newLogger._isFatalEnabled = true; - return newLogger; - } - /// /// Occurs when logger configuration changes. /// @@ -125,6 +97,50 @@ public bool IsEnabled(LogLevel level) return GetTargetsForLevel(level) != null; } + /// + /// Creates new logger that automatically appends the specified property to all log events (without changing current logger) + /// + /// Property Name + /// Property Value + /// New Logger object that automatically appends specified property + public Logger WithProperty(string propertyKey, object propertyValue) + { + if (string.IsNullOrEmpty(propertyKey)) + throw new ArgumentException(nameof(propertyKey)); + + Logger newLogger = Factory.CreateNewLogger(GetType()) ?? new Logger(); + newLogger.Initialize(Name, _configuration, Factory); + newLogger._contextProperties = CopyOnWrite(propertyKey, propertyValue); + newLogger._contextLogger = _contextLogger; // Use the LoggerConfiguration of the parent Logger + return newLogger; + } + + /// + /// Updates the specified context property for the current logger. The logger will append it for all log events + /// + /// + /// Will affect all locations/contexts that makes use of the same named logger object. + /// + /// Property Name + /// Property Value + public void SetProperty(string propertyKey, object propertyValue) + { + if (string.IsNullOrEmpty(propertyKey)) + throw new ArgumentException(nameof(propertyKey)); + + _contextProperties = CopyOnWrite(propertyKey, propertyValue); + } + + private Dictionary CopyOnWrite(string propertyKey, object propertyValue) + { + var contextProperties = _contextProperties; + contextProperties = contextProperties != null + ? new Dictionary(contextProperties) + : new Dictionary(); + contextProperties[propertyKey] = propertyValue; + return contextProperties; + } + /// /// Writes the specified diagnostic message. /// @@ -675,7 +691,7 @@ private TargetWithFilterChain GetTargetsForLevel(LogLevel level) if (ReferenceEquals(_contextLogger, this)) return _configuration.GetTargetsForLevel(level); else - return _contextLogger.GetTargetsForLevel(level); + return _contextLogger.GetTargetsForLevel(level); // Use the LoggerConfiguration of the parent Logger } /// diff --git a/tests/NLog.UnitTests/LoggerTests.cs b/tests/NLog.UnitTests/LoggerTests.cs index 89788e7c53..e76d879fc2 100644 --- a/tests/NLog.UnitTests/LoggerTests.cs +++ b/tests/NLog.UnitTests/LoggerTests.cs @@ -2393,9 +2393,9 @@ public void LogEventTemplateShouldHaveProperties_even_when_changed() static Logger GetContextLoggerFromTemporary(string loggerName) { - var loggerRaw = LogManager.GetLogger(loggerName); - var loggerStage1 = loggerRaw.WithProperty("Stage", 1); - loggerRaw.Trace("{Stage}", "Connected"); + var globalLogger = LogManager.GetLogger(loggerName); + var loggerStage1 = globalLogger.WithProperty("Stage", 1); + globalLogger.Trace("{Stage}", "Connected"); return loggerStage1; } @@ -2409,7 +2409,7 @@ public void LogEventTemplateShouldOverrideProperties() config.LoggingRules.Add(new LoggingRule(uniqueLoggerName, LogLevel.Trace, target)); LogManager.Configuration = config; Logger loggerStage1 = GetContextLoggerFromTemporary(uniqueLoggerName); - GC.Collect(); // Try and free loggerRaw + GC.Collect(); // Try and free globalLogger var loggerStage2 = loggerStage1.WithProperty("Stage", 2); Assert.Single(target.LastEvent.Properties); AssertContainsInDictionary(target.LastEvent.Properties, "Stage", "Connected"); @@ -2436,16 +2436,40 @@ public void LoggerWithPropertyShouldInheritLogLevel() config.LoggingRules.Add(new LoggingRule(uniqueLoggerName, LogLevel.Trace, target)); LogManager.Configuration = config; Logger loggerStage1 = GetContextLoggerFromTemporary(uniqueLoggerName); - GC.Collect(); // Try and free loggerRaw + GC.Collect(); // Try and free globalLogger Assert.Single(target.LastEvent.Properties); AssertContainsInDictionary(target.LastEvent.Properties, "Stage", "Connected"); LogManager.Configuration.LoggingRules[0].DisableLoggingForLevel(LogLevel.Trace); - LogManager.ReconfigExistingLoggers(); // Refreshes the configuration of loggerRaw + LogManager.ReconfigExistingLoggers(); // Refreshes the configuration of globalLogger var loggerStage2 = loggerStage1.WithProperty("Stage", 2); loggerStage2.Trace("Login attempt from {userid}", "kermit"); AssertContainsInDictionary(target.LastEvent.Properties, "Stage", "Connected"); // Verify nothing writtne loggerStage2.Debug("{Stage}", "Disconnected"); AssertContainsInDictionary(target.LastEvent.Properties, "Stage", "Disconnected"); } + + [Fact] + public void LoggerSetPropertyChangesCurrentLogger() + { + string uniqueLoggerName = Guid.NewGuid().ToString(); + + var config = new LoggingConfiguration(); + var target = new MyTarget(); + config.LoggingRules.Add(new LoggingRule(uniqueLoggerName, LogLevel.Trace, target)); + LogManager.Configuration = config; + var globalLogger = LogManager.GetLogger(uniqueLoggerName); + globalLogger.SetProperty("Stage", 1); + globalLogger.Trace("Login attempt from {userid}", "kermit"); + AssertContainsInDictionary(target.LastEvent.Properties, "Stage", 1); + var loggerStage2 = globalLogger.WithProperty("Stage", 2); + loggerStage2.Trace("Hello from {userid}", "kermit"); + AssertContainsInDictionary(target.LastEvent.Properties, "Stage", 2); + globalLogger.SetProperty("Stage", 4); + loggerStage2.SetProperty("Stage", 3); + loggerStage2.Trace("Goodbye from {userid}", "kermit"); + AssertContainsInDictionary(target.LastEvent.Properties, "Stage", 3); + globalLogger.Trace("Logoff by {userid}", "kermit"); + AssertContainsInDictionary(target.LastEvent.Properties, "Stage", 4); + } } } From 7b4bf0144591d11556c58d5a9b1e83276ef21d8e Mon Sep 17 00:00:00 2001 From: Rolf Kristensen Date: Sun, 14 Apr 2019 22:59:50 +0200 Subject: [PATCH 10/57] StringHelpers - SplitAndTrimTokens --- src/NLog/Config/LoggingConfigurationParser.cs | 24 +++--------------- .../Internal/Fakeables/AppDomainWrapper.cs | 2 +- src/NLog/Internal/PropertyHelper.cs | 2 +- src/NLog/Internal/StackTraceUsageUtils.cs | 2 +- src/NLog/Internal/StringHelpers.cs | 25 +++++++++++++++++-- .../AssemblyVersionLayoutRenderer.cs | 2 +- .../ExceptionLayoutRenderer.cs | 2 +- src/NLog/Targets/DatabaseParameterInfo.cs | 2 +- src/NLog/Targets/MailTarget.cs | 2 +- 9 files changed, 34 insertions(+), 29 deletions(-) diff --git a/src/NLog/Config/LoggingConfigurationParser.cs b/src/NLog/Config/LoggingConfigurationParser.cs index 93b1b1dcb7..a193162a42 100644 --- a/src/NLog/Config/LoggingConfigurationParser.cs +++ b/src/NLog/Config/LoggingConfigurationParser.cs @@ -610,8 +610,8 @@ private LoggingRule ParseRuleElement(ILoggingConfigurationElement loggerElement) break; case "LEVELS": { - string[] tokens = CleanSpaces(childProperty.Value).Split(','); - enableLevels = tokens.Where(t => !string.IsNullOrEmpty(t)).Select(LogLevelFromString); + string[] tokens = childProperty.Value.SplitAndTrimTokens(','); + enableLevels = tokens.Select(LogLevelFromString); break; } case "MINLEVEL": @@ -680,12 +680,8 @@ private void ParseLoggingRuleTargets(string writeTargets, LoggingRule rule) if (string.IsNullOrEmpty(writeTargets)) return; - foreach (string t in writeTargets.Split(',')) + foreach (string targetName in writeTargets.SplitAndTrimTokens(',')) { - string targetName = t.Trim(); - if (string.IsNullOrEmpty(targetName)) - continue; - Target target = FindTargetByName(targetName); if (target != null) { @@ -1227,19 +1223,7 @@ private static string StripOptionalNamespacePrefix(string attributeValue) return attributeValue.Substring(p + 1); } - - /// - /// Remove all spaces, also in between text. - /// - /// text - /// text without spaces - /// Tabs and other whitespace is not removed! - private static string CleanSpaces(string s) - { - s = s.Replace(" ", string.Empty); // get rid of the whitespace - return s; - } - + private static string GetName(Target target) { return string.IsNullOrEmpty(target.Name) ? target.GetType().Name : target.Name; diff --git a/src/NLog/Internal/Fakeables/AppDomainWrapper.cs b/src/NLog/Internal/Fakeables/AppDomainWrapper.cs index df90f7e475..b1a4424f14 100644 --- a/src/NLog/Internal/Fakeables/AppDomainWrapper.cs +++ b/src/NLog/Internal/Fakeables/AppDomainWrapper.cs @@ -118,7 +118,7 @@ private static string[] LookupPrivateBinPath(AppDomain appDomain) string privateBinPath = appDomain.SetupInformation.PrivateBinPath; return string.IsNullOrEmpty(privateBinPath) ? ArrayHelper.Empty() - : privateBinPath.Split(new[] { ';' }, StringSplitOptions.RemoveEmptyEntries); + : privateBinPath.SplitAndTrimTokens(';'); #else return ArrayHelper.Empty(); #endif diff --git a/src/NLog/Internal/PropertyHelper.cs b/src/NLog/Internal/PropertyHelper.cs index bc9aadda9a..ab6d3f3da0 100644 --- a/src/NLog/Internal/PropertyHelper.cs +++ b/src/NLog/Internal/PropertyHelper.cs @@ -260,7 +260,7 @@ private static bool TryGetEnumValue(Type resultType, string value, out object re { ulong union = 0; - foreach (string v in value.Split(',')) + foreach (string v in value.SplitAndTrimTokens(',')) { FieldInfo enumField = resultType.GetField(v.Trim(), BindingFlags.IgnoreCase | BindingFlags.Static | BindingFlags.FlattenHierarchy | BindingFlags.Public); if (enumField == null) diff --git a/src/NLog/Internal/StackTraceUsageUtils.cs b/src/NLog/Internal/StackTraceUsageUtils.cs index 66f4e840be..8ab989b14e 100644 --- a/src/NLog/Internal/StackTraceUsageUtils.cs +++ b/src/NLog/Internal/StackTraceUsageUtils.cs @@ -156,7 +156,7 @@ public static string GetClassFullName() className = GetClassFullName(stackFrame); #else var stackTrace = Environment.StackTrace; - var stackTraceLines = stackTrace.Replace("\r", "").Split(new[] { "\n" }, StringSplitOptions.RemoveEmptyEntries); + var stackTraceLines = stackTrace.Replace("\r", "").SplitAndTrimTokens('\n'); for (int i = 0; i < stackTraceLines.Length; ++i) { var callingClassAndMethod = stackTraceLines[i].Split(new[] { " ", "<>", "(", ")" }, StringSplitOptions.RemoveEmptyEntries)[1]; diff --git a/src/NLog/Internal/StringHelpers.cs b/src/NLog/Internal/StringHelpers.cs index c2d410d874..cbdf23f5b0 100644 --- a/src/NLog/Internal/StringHelpers.cs +++ b/src/NLog/Internal/StringHelpers.cs @@ -32,7 +32,6 @@ // using System; -using System.Collections.Generic; using System.Linq; using JetBrains.Annotations; @@ -51,7 +50,6 @@ public static class StringHelpers [ContractAnnotation("value:null => true")] internal static bool IsNullOrWhiteSpace(string value) { - #if NET3_5 if (value == null) return true; @@ -61,5 +59,28 @@ internal static bool IsNullOrWhiteSpace(string value) return string.IsNullOrWhiteSpace(value); #endif } + + internal static string[] SplitAndTrimTokens(this string value, char delimiter) + { + if (IsNullOrWhiteSpace(value)) + return ArrayHelper.Empty(); + + if (value.IndexOf(delimiter) == -1) + { + return new[] { value.Trim() }; + } + + var result = value.Split(new char[] { delimiter }, StringSplitOptions.RemoveEmptyEntries); + for (int i = 0; i < result.Length; ++i) + { + if (char.IsWhiteSpace(result[i][0]) || char.IsWhiteSpace(result[i][result[i].Length - 1])) + { + result[i] = result[i].Trim(); + if (string.IsNullOrEmpty(result[i])) + return result.Where(s => !IsNullOrWhiteSpace(s)).Select(s => s.Trim()).ToArray(); + } + } + return result; + } } } diff --git a/src/NLog/LayoutRenderers/AssemblyVersionLayoutRenderer.cs b/src/NLog/LayoutRenderers/AssemblyVersionLayoutRenderer.cs index de6f08ac4a..3b87d77aed 100644 --- a/src/NLog/LayoutRenderers/AssemblyVersionLayoutRenderer.cs +++ b/src/NLog/LayoutRenderers/AssemblyVersionLayoutRenderer.cs @@ -148,7 +148,7 @@ private string ApplyFormatToVersion(string version) return version; } - var versionParts = version.Split('.'); + var versionParts = version.SplitAndTrimTokens('.'); version = Format.Replace("major", versionParts[0]) .Replace("minor", versionParts.Length > 1 ? versionParts[1] : "0") .Replace("build", versionParts.Length > 2 ? versionParts[2] : "0") diff --git a/src/NLog/LayoutRenderers/ExceptionLayoutRenderer.cs b/src/NLog/LayoutRenderers/ExceptionLayoutRenderer.cs index d9189aa1e0..aac3f9d49a 100644 --- a/src/NLog/LayoutRenderers/ExceptionLayoutRenderer.cs +++ b/src/NLog/LayoutRenderers/ExceptionLayoutRenderer.cs @@ -409,7 +409,7 @@ protected virtual void AppendSerializeObject(StringBuilder sb, Exception ex) private static List CompileFormat(string formatSpecifier) { List formats = new List(); - string[] parts = formatSpecifier.Replace(" ", string.Empty).Split(new string[] { "," }, StringSplitOptions.RemoveEmptyEntries); + string[] parts = formatSpecifier.SplitAndTrimTokens(','); foreach (string s in parts) { diff --git a/src/NLog/Targets/DatabaseParameterInfo.cs b/src/NLog/Targets/DatabaseParameterInfo.cs index f4ed276743..155b30f358 100644 --- a/src/NLog/Targets/DatabaseParameterInfo.cs +++ b/src/NLog/Targets/DatabaseParameterInfo.cs @@ -167,7 +167,7 @@ public DbTypeSetter(Type dbParameterType, string dbTypeName) _dbTypeName = dbTypeName; if (!StringHelpers.IsNullOrWhiteSpace(dbTypeName)) { - string[] dbTypeNames = dbTypeName.Split(new[] { '.' }, StringSplitOptions.RemoveEmptyEntries); + string[] dbTypeNames = dbTypeName.SplitAndTrimTokens('.'); if (dbTypeNames.Length > 1 && !string.Equals(dbTypeNames[0], nameof(System.Data.DbType), StringComparison.OrdinalIgnoreCase)) { PropertyInfo propInfo = dbParameterType.GetProperty(dbTypeNames[0], BindingFlags.IgnoreCase | BindingFlags.Public | BindingFlags.Instance); diff --git a/src/NLog/Targets/MailTarget.cs b/src/NLog/Targets/MailTarget.cs index 5d6d95a7e6..e30f6a1f64 100644 --- a/src/NLog/Targets/MailTarget.cs +++ b/src/NLog/Targets/MailTarget.cs @@ -681,7 +681,7 @@ private static bool AddAddresses(MailAddressCollection mailAddressCollection, La var added = false; if (layout != null) { - foreach (string mail in layout.Render(logEvent).Split(new char[] { ';' }, StringSplitOptions.RemoveEmptyEntries)) + foreach (string mail in layout.Render(logEvent).SplitAndTrimTokens(';')) { mailAddressCollection.Add(mail); added = true; From 85b32e0c133eb2f089d953b644d244c91ee9cf2e Mon Sep 17 00:00:00 2001 From: Julian Verdurmen <304NotModified@users.noreply.github.com> Date: Sun, 14 Apr 2019 23:17:52 +0200 Subject: [PATCH 11/57] Sonar: status to branch "dev" --- README.md | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/README.md b/README.md index 93b1834649..5fd8ca1fe7 100644 --- a/README.md +++ b/README.md @@ -7,12 +7,12 @@ [![license](https://img.shields.io/github/license/mashape/apistatus.svg)]() -[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=ncloc)](https://sonarcloud.io/dashboard/?id=nlog) -[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=bugs)](https://sonarcloud.io/dashboard/?id=nlog) -[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=vulnerabilities)](https://sonarcloud.io/dashboard/?id=nlog) -[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=code_smells)](https://sonarcloud.io/project/issues?id=nlog&resolved=false&types=CODE_SMELL) -[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=duplicated_lines_density)](https://sonarcloud.io/component_measures/domain/Duplications?id=nlog) -[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=sqale_debt_ratio)](https://sonarcloud.io/dashboard/?id=nlog) +[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=ncloc&branch=dev)](https://sonarcloud.io/dashboard/?id=nlog&branch=dev) +[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=bugs&branch=dev)](https://sonarcloud.io/dashboard/?id=nlog&branch=dev) +[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=vulnerabilities&branch=dev)](https://sonarcloud.io/dashboard/?id=nlog&branch=dev) +[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=code_smells&branch=dev)](https://sonarcloud.io/project/issues?id=nlog&resolved=false&types=CODE_SMELL&branch=dev) +[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=duplicated_lines_density&branch=dev)](https://sonarcloud.io/component_measures/domain/Duplications?id=nlog&branch=dev) +[![](https://sonarcloud.io/api/project_badges/measure?project=nlog&metric=sqale_debt_ratio&branch=dev)](https://sonarcloud.io/dashboard/?id=nlog&branch=dev) [![codecov.io](https://codecov.io/github/NLog/NLog/coverage.svg?branch=dev)](https://codecov.io/github/NLog/NLog?branch=dev)