Merge pull request #246 from servicetitan/upstream/optimize_Logging

Optimize logging. Logging uses message identifiers (names of properties in resources)
instead of properties itself, it allows to postpone getting actual string which is good
in cases when logging is off entirely or partially. It also supports regular messages
if they're needed.

Author: alex-kulakov

Extensions/Xtensive.Orm.Logging.NLog/Log.cs

@@ -1,4 +1,4 @@
-// Copyright (C) 2013-2020 Xtensive LLC.
+// Copyright (C) 2013-2020 Xtensive LLC.
 // This code is distributed under MIT license terms.
 // See the License.txt file in the project root for more information.
 // Created by: Dmitri Maximov
@@ -40,7 +40,7 @@ public override bool IsLogged(LogLevel level)
     }
 
     /// <inheritdoc/>
-    public override void Write(LogEventInfo info)
+    public override void Write(in LogEventInfo info)
     {
       if (info.Exception!=null)
         target.Log(ConvertLevel(info.Level), info.Exception, info.FormattedMessage);

Extensions/Xtensive.Orm.Logging.log4net/Log.cs

@@ -1,4 +1,4 @@
-// Copyright (C) 2014-2020 Xtensive LLC.
+// Copyright (C) 2014-2020 Xtensive LLC.
 // This code is distributed under MIT license terms.
 // See the License.txt file in the project root for more information.
 // Created by: Alexey Kulakov
@@ -43,7 +43,7 @@ public override bool IsLogged(LogLevel level)
     }
 
     /// <inheritdoc />
-    public override void Write(LogEventInfo info)
+    public override void Write(in LogEventInfo info)
     {
       target.Logger.Log(target.Logger.GetType(), ConvertLevel(info.Level), info.FormattedMessage, info.Exception);
     }

Orm/Xtensive.Orm.Tests.Core/DotNetFramework/NewTupleLogicTest.cs

@@ -145,12 +145,18 @@ public void PeformanceTest()
 
     private void Test(int count)
     {
-      using (warmup ? new Disposable(delegate { }) :
-        TestLog.InfoRegion("With boxing"))
+      if (warmup) {
         TestTupleAccess(new BoxingTuple(), count);
-      using (warmup ? new Disposable(delegate { }) :
-        TestLog.InfoRegion("Without boxing"))
         TestTupleAccess(new NonBoxingTuple(), count);
+      }
+      else {
+        using(TestLog.InfoRegion("With boxing")) {
+          TestTupleAccess(new BoxingTuple(), count);
+        }
+        using (TestLog.InfoRegion("Without boxing")) {
+          TestTupleAccess(new NonBoxingTuple(), count);
+        }
+      }
     }
 
     private void TestTupleAccess(TestTuple tuple, int count)

Orm/Xtensive.Orm.Tests.Core/DotNetFramework/ThreadingTest.cs

@@ -219,7 +219,7 @@ private void LockTest(double speedFactor, int threadCount)
         passCountBase /= 10;
 
       TestHelper.CollectGarbage();
-      using (warmup ? null : TestLog.InfoRegion(string.Format("{0} threads", threadCount))) {
+      if (warmup) {
         ThreadedTest(target, passCountBase,     target.ExecuteLock);
         ThreadedTest(target, passCountBase,     target.ExecuteReadLock);
         ThreadedTest(target, passCountBase,     target.ExecuteWriteLock);
@@ -228,6 +228,17 @@ private void LockTest(double speedFactor, int threadCount)
           ThreadedTest(target, passCountBase / 400, target.ExecuteSleepLock);
         }
       }
+      else {
+        using (TestLog.InfoRegion(string.Format("{0} threads", threadCount))) {
+          ThreadedTest(target, passCountBase,     target.ExecuteLock);
+          ThreadedTest(target, passCountBase,     target.ExecuteReadLock);
+          ThreadedTest(target, passCountBase,     target.ExecuteWriteLock);
+          if (threadCount>1) {
+            ThreadedTest(target, passCountBase / 200, target.ExecuteWaitLock);
+            ThreadedTest(target, passCountBase / 400, target.ExecuteSleepLock);
+          }
+        }
+      }
     }
 
     private void InvokeAsyncTest(double speedFactor, int threadCount)
@@ -240,9 +251,14 @@ private void InvokeAsyncTest(double speedFactor, int threadCount)
         passCountBase /= 10;
 
       TestHelper.CollectGarbage();
-      using (warmup ? null : TestLog.InfoRegion(string.Format("{0} threads", threadCount))) {
+      if (warmup) {
         ThreadedTest(target, passCountBase/100, target.ExecuteInvokeAsync);
       }
+      else {
+        using (TestLog.InfoRegion(string.Format("{0} threads", threadCount))) {
+          ThreadedTest(target, passCountBase/100, target.ExecuteInvokeAsync);
+        }
+      }
     }
 
     private static void ThreadedTest(Target target, int passCount, ParameterizedThreadStart method)

Orm/Xtensive.Orm/Comparison/ComparerProvider.cs

@@ -66,7 +66,7 @@ protected override TAssociate CreateAssociate<TKey, TAssociate>(out Type foundFo
       // the comparer.
       var comparer = base.CreateAssociate<TKey, IAdvancedComparerBase>(out foundFor);
       if (foundFor == null) {
-        CoreLog.Warning(Strings.LogCantFindAssociateFor,
+        CoreLog.Warning(nameof(Strings.LogCantFindAssociateFor),
           TypeSuffixes.ToDelimitedString(" \\ "),
           typeof(TAssociate).GetShortName(),
           typeof(TKey).GetShortName());
@@ -77,15 +77,15 @@ protected override TAssociate CreateAssociate<TKey, TAssociate>(out Type foundFo
       }
       associate = BaseComparerWrapperType.Activate(new[] { typeof(TKey), foundFor }, ConstructorParams) as TAssociate;
       if (associate != null) {
-        CoreLog.Warning(Strings.LogGenericAssociateIsUsedFor,
+        CoreLog.Warning(nameof(Strings.LogGenericAssociateIsUsedFor),
           BaseComparerWrapperType.GetShortName(),
           typeof (TKey).GetShortName(),
           foundFor.GetShortName(),
           typeof (TKey).GetShortName());
         return associate;
       }
       else {
-        CoreLog.Warning(Strings.LogGenericAssociateCreationHasFailedFor,
+        CoreLog.Warning(nameof(Strings.LogGenericAssociateCreationHasFailedFor),
           BaseComparerWrapperType.GetShortName(),
           typeof (TKey).GetShortName(),
           foundFor.GetShortName(),

Orm/Xtensive.Orm/Core/AsyncFutureResult.cs

@@ -53,7 +53,7 @@ public override void Dispose()
         Get();
       }
       catch (Exception exception) {
-        logger?.Warning(Strings.LogAsyncOperationError, exception: exception);
+        logger?.Warning(nameof(Strings.LogAsyncOperationError), exception: exception);
       }
     }
 
@@ -67,7 +67,7 @@ public override async ValueTask DisposeAsync()
         await GetAsync().ConfigureAwait(false);
       }
       catch (Exception exception) {
-        logger?.Warning(Strings.LogAsyncOperationError, exception: exception);
+        logger?.Warning(nameof(Strings.LogAsyncOperationError), exception: exception);
       }
     }