[dotnet] Improve logging performance when it is disabled (#13464)

* Use IsEnabledFor before allocate log message

* Rename to `IsEnabled`

* Simplify determination of logger's level

Author: nvborisenko

dotnet/src/webdriver/DriverService.cs

@@ -239,7 +239,10 @@ protected virtual bool IsInitialized
                 }
                 catch (Exception ex) when (ex is HttpRequestException || ex is TaskCanceledException)
                 {
-                    logger.Trace(ex.ToString());
+                    if (logger.IsEnabled(LogEventLevel.Trace))
+                    {
+                        logger.Trace(ex.ToString());
+                    }
                 }
 
                 return isInitialized;

dotnet/src/webdriver/Internal/FileUtilities.cs

@@ -102,7 +102,10 @@ public static void DeleteDirectory(string directoryToDelete)
 
             if (Directory.Exists(directoryToDelete))
             {
-                logger.Trace($"Unable to delete directory '{directoryToDelete}'");
+                if (logger.IsEnabled(LogEventLevel.Trace))
+                {
+                    logger.Trace($"Unable to delete directory '{directoryToDelete}'");
+                }
             }
         }
 

dotnet/src/webdriver/Internal/Logging/ILogContext.cs

@@ -52,6 +52,14 @@ public interface ILogContext : IDisposable
         /// <returns>An instance of <see cref="ILogger"/> for the specified type.</returns>
         internal ILogger GetLogger(Type type);
 
+        /// <summary>
+        /// Checks whether logs emitting is enabled for a logger and a log event level.
+        /// </summary>
+        /// <param name="logger">The specified logger instance to be checked.</param>
+        /// <param name="level">The specified log event level to be checked.</param>
+        /// <returns><c>true</c> if log messages emmiting is enabled for the specified logger and log event level, otherwise <c>false</c>.</returns>
+        internal bool IsEnabled(ILogger logger, LogEventLevel level);
+
         /// <summary>
         /// Emits a log message using the specified logger, log level, and message.
         /// </summary>

dotnet/src/webdriver/Internal/Logging/ILogger.cs

@@ -64,5 +64,12 @@ internal interface ILogger
         /// Gets the type of the logger issuer.
         /// </summary>
         Type Issuer { get; }
+
+        /// <summary>
+        /// Checks whether logs emitting is enabled for this logger and a log event level.
+        /// </summary>
+        /// <param name="level">The specified log event level to be checked.</param>
+        /// <returns><c>true</c> if log messages emmiting is enabled for the specified log event level, otherwise <c>false</c>.</returns>
+        bool IsEnabled(LogEventLevel level);
     }
 }

dotnet/src/webdriver/Internal/Logging/LogContext.cs

@@ -96,9 +96,14 @@ public ILogger GetLogger(Type type)
             return _loggers.GetOrAdd(type, _ => new Logger(type, _level));
         }
 
+        public bool IsEnabled(ILogger logger, LogEventLevel level)
+        {
+            return Handlers != null && level >= _level && level >= logger.Level;
+        }
+
         public void EmitMessage(ILogger logger, LogEventLevel level, string message)
         {
-            if (Handlers != null && level >= _level && level >= GetLogger(logger.Issuer).Level)
+            if (IsEnabled(logger, level))
             {
                 var logEvent = new LogEvent(logger.Issuer, DateTimeOffset.Now, level, message);
 

dotnet/src/webdriver/Internal/Logging/Logger.cs

@@ -61,6 +61,11 @@ public void Error(string message)
             LogMessage(LogEventLevel.Error, message);
         }
 
+        public bool IsEnabled(LogEventLevel level)
+        {
+            return Log.CurrentContext.IsEnabled(this, level);
+        }
+
         private void LogMessage(LogEventLevel level, string message)
         {
             Log.CurrentContext.EmitMessage(this, level, message);

dotnet/src/webdriver/Remote/HttpCommandExecutor.cs

@@ -18,14 +18,12 @@
 
 using System;
 using System.Collections.Generic;
-using System.Diagnostics;
 using System.Globalization;
 using System.Linq;
 using System.Net;
 using System.Net.Http;
 using System.Net.Http.Headers;
 using System.Text;
-using System.Threading;
 using System.Threading.Tasks;
 using OpenQA.Selenium.Internal;
 using OpenQA.Selenium.Internal.Logging;
@@ -166,7 +164,10 @@ public virtual Response Execute(Command commandToExecute)
                 throw new ArgumentNullException(nameof(commandToExecute), "commandToExecute cannot be null");
             }
 
-            _logger.Debug($"Executing command: {commandToExecute}");
+            if (_logger.IsEnabled(LogEventLevel.Debug))
+            {
+                _logger.Debug($"Executing command: {commandToExecute}");
+            }
 
             HttpCommandInfo info = this.commandInfoRepository.GetCommandInfo<HttpCommandInfo>(commandToExecute.Name);
             if (info == null)
@@ -198,7 +199,10 @@ public virtual Response Execute(Command commandToExecute)
 
             Response toReturn = this.CreateResponse(responseInfo);
 
-            _logger.Debug($"Response: {toReturn}");
+            if (_logger.IsEnabled(LogEventLevel.Debug))
+            {
+                _logger.Debug($"Response: {toReturn}");
+            }
 
             return toReturn;
         }
@@ -279,11 +283,17 @@ private async Task<HttpResponseInfo> MakeHttpRequest(HttpRequestInfo requestInfo
                     requestMessage.Content.Headers.ContentType = contentTypeHeader;
                 }
 
-                _logger.Trace($">> {requestMessage}");
+                if (_logger.IsEnabled(LogEventLevel.Trace))
+                {
+                    _logger.Trace($">> {requestMessage}");
+                }
 
                 using (HttpResponseMessage responseMessage = await this.client.SendAsync(requestMessage).ConfigureAwait(false))
                 {
-                    _logger.Trace($"<< {responseMessage}");
+                    if (_logger.IsEnabled(LogEventLevel.Trace))
+                    {
+                        _logger.Trace($"<< {responseMessage}");
+                    }
 
                     HttpResponseInfo httpResponseInfo = new HttpResponseInfo();
                     httpResponseInfo.Body = await responseMessage.Content.ReadAsStringAsync().ConfigureAwait(false);

dotnet/src/webdriver/Safari/SafariDriverService.cs

@@ -130,7 +130,10 @@ protected override bool IsInitialized
                         // check.
                         catch (Exception ex) when (ex is HttpRequestException || ex is TaskCanceledException)
                         {
-                            logger.Trace(ex.ToString());
+                            if (logger.IsEnabled(LogEventLevel.Trace))
+                            {
+                                logger.Trace(ex.ToString());
+                            }
                         }
                     }
                 }

dotnet/src/webdriver/SeleniumManager.cs

@@ -121,7 +121,10 @@ public static string DriverPath(DriverOptions options)
 
             var driverPath = (string)output["driver_path"];
 
-            _logger.Trace($"Driver path: {driverPath}");
+            if (_logger.IsEnabled(LogEventLevel.Trace))
+            {
+                _logger.Trace($"Driver path: {driverPath}");
+            }
 
             return driverPath;
         }