Re-Entrancy Scope Lock for Session Value Layout Render (#850)

Co-authored-by: Burak Akgerman <[email protected]>

src/Shared/Internal/ReEntrantScopeLock.cs

@@ -0,0 +1,100 @@
+using System;
+#if !NET35
+using System.Threading;
+#endif
+#if ASP_NET_CORE
+using HttpContextBase = Microsoft.AspNetCore.Http.HttpContext;
+#else
+using System.Web;
+#endif
+
+namespace NLog.Web.Internal
+{
+    /// <summary>
+    /// Manages if a LayoutRenderer can be called recursively.
+    /// Especially used by AspNetSessionValueLayoutRenderer
+    /// 
+    /// Since NET 35 does not support AsyncLocal or even ThreadLocal
+    /// a different technique must be used for that platform
+    /// </summary>
+    internal readonly struct ReEntrantScopeLock : IDisposable
+    {
+        internal ReEntrantScopeLock(HttpContextBase context)
+        {
+            _httpContext = context;
+            IsLockAcquired = TryGetLock(context);
+        }
+
+        private readonly HttpContextBase _httpContext;
+
+        // Need to track if we were successful in the lock
+        // If we were not, we should not unlock in the dispose code
+        internal bool IsLockAcquired { get; }
+
+#if NET35
+        private static readonly object ReEntrantLock = new object();
+
+        private static bool TryGetLock(HttpContextBase context)
+        {
+            // If context is null leave
+            if (context == null)
+            {
+                return false;
+            }
+
+            // If already locked, return false
+            if (context.Items?.Contains(ReEntrantLock) == true)
+            {
+                return false;
+            }
+
+            // Get the lock
+            context.Items[ReEntrantLock] = bool.TrueString;
+
+            // Indicate the lock was successfully acquired
+            return true;
+        }
+
+        public void Dispose()
+        {
+            // Only unlock if we were the ones who locked it
+            if (IsLockAcquired)
+            {
+                _httpContext.Items?.Remove(ReEntrantLock);
+            }
+        }
+#else
+        private static readonly AsyncLocal<bool> ReEntrantLock = new AsyncLocal<bool>();
+
+        private static bool TryGetLock(HttpContextBase context)
+        {
+            // If context is null leave
+            if (context == null)
+            {
+                return false;
+            }
+
+            // If already locked, return false
+            if (ReEntrantLock.Value)
+            {
+                return false;
+            }
+
+            // Get the lock
+            ReEntrantLock.Value = true;
+
+            // Indicate the lock was successfully acquired
+            return true;
+        }
+
+        public void Dispose()
+        {
+            // Only unlock if we were the ones who locked it
+            if (IsLockAcquired)
+            {
+                ReEntrantLock.Value = false;
+            }
+        }
+#endif
+    }
+}

src/Shared/LayoutRenderers/AspNetSessionValueLayoutRenderer.cs

@@ -1,13 +1,13 @@
-using System;
 using System.Globalization;
 using System.Text;
 using NLog.Config;
 using NLog.LayoutRenderers;
 using NLog.Web.Internal;
-#if !ASP_NET_CORE
-using System.Web;
-#else
+using NLog.Common;
+#if ASP_NET_CORE
 using Microsoft.AspNetCore.Http;
+#else
+using System.Web;
 #endif
 
 namespace NLog.Web.LayoutRenderers
@@ -40,10 +40,6 @@ namespace NLog.Web.LayoutRenderers
     [LayoutRenderer("aspnet-session")]
     public class AspNetSessionValueLayoutRenderer : AspNetLayoutRendererBase
     {
-#if ASP_NET_CORE
-        private static readonly object NLogRetrievingSessionValue = new object();
-#endif
-
         /// <summary>
         /// Gets or sets the session item name.
         /// </summary>
@@ -78,7 +74,7 @@ public class AspNetSessionValueLayoutRenderer : AspNetLayoutRendererBase
 
 #if ASP_NET_CORE
         /// <summary>
-        /// The hype of the value.
+        /// The type of the value.
         /// </summary>
         public SessionValueType ValueType { get; set; } = SessionValueType.String;
 #endif
@@ -93,36 +89,36 @@ protected override void DoAppend(StringBuilder builder, LogEventInfo logEvent)
             }
 
             var context = HttpContextAccessor.HttpContext;
-            var contextSession = context.TryGetSession();
-            if (contextSession == null)
-                return;
-
-#if !ASP_NET_CORE
-            var value = PropertyReader.GetValue(item, contextSession, (session,key) => session.Count > 0 ? session[key] : null, EvaluateAsNestedProperties);
-#else
-            //because session.get / session.getstring also creating log messages in some cases, this could lead to stackoverflow issues. 
-            //We remember on the context.Items that we are looking up a session value so we prevent stackoverflows
-            if (context.Items == null || (context.Items.Count > 0 && context.Items.ContainsKey(NLogRetrievingSessionValue)))
+            if (context == null)
             {
                 return;
             }
 
-            context.Items[NLogRetrievingSessionValue] = bool.TrueString;
-
-            object value;
-            try
-            {
-                value = PropertyReader.GetValue(item, contextSession, (session, key) => GetSessionValue(session, key), EvaluateAsNestedProperties);
-            }
-            finally
+            var contextSession = context?.TryGetSession();
+            if (contextSession == null)
             {
-                context.Items.Remove(NLogRetrievingSessionValue);
+                return;
             }
-#endif
-            if (value != null)
+
+            // Because session.get / session.getstring are also creating log messages in some cases,
+            //   this could lead to stack overflow issues. 
+            // We remember that we are looking up a session value so we prevent stack overflows
+            using (var reEntry = new ReEntrantScopeLock(context))
             {
-                var formatProvider = GetFormatProvider(logEvent, Culture);
-                builder.AppendFormattedValue(value, Format, formatProvider, ValueFormatter);
+                if (!reEntry.IsLockAcquired)
+                {
+                    InternalLogger.Debug(
+                        "Reentrant log event detected. Logging when inside the scope of another log event can cause a StackOverflowException.");
+                    return;
+                }
+
+                var value = PropertyReader.GetValue(item, contextSession, GetSessionValue, EvaluateAsNestedProperties);
+
+                if (value != null)
+                {
+                    var formatProvider = GetFormatProvider(logEvent, Culture);
+                    builder.AppendFormattedValue(value, Format, formatProvider, ValueFormatter);
+                }
             }
         }
 
@@ -133,9 +129,16 @@ private object GetSessionValue(ISession session, string key)
             {
                 case SessionValueType.Int32:
                     return session.GetInt32(key);
-                default: return session.GetString(key);
+                default: 
+                    return session.GetString(key);
             }
         }
+#else
+        private object GetSessionValue(HttpSessionStateBase session, string key)
+        {
+            return session.Count == 0 ? null : session[key];
+        }
 #endif
+
     }
 }