[dotnet] Enabling drivers to set log to console. (#16097)

* [dotnet] Enabling drivers to set log to console.

This will be false by default, following what the

.NET bindings have usually done.

Helps with #12273

* [dotnet] Avoid changing state of variable.

LogPath takes precedence anyway.

* Using existing logger functionality.

Messages will be shown to the console
using the Logger functionality.

Adding a test that listens to the
logger and checks that logs are being
sent to console.

Fixing an issue when sending the log
to a file, as the OnDriverProcessStarted
method in the base class was not being
invoked.

* Running format script.

* WriteDriverLogToConsole

Internal variable to avoid using
the stream when logs are sent to a file.

Not exposed to the user.

* Format script.

* Update dotnet/src/webdriver/DriverService.cs

Co-authored-by: Nikolay Borisenko <[email protected]>

* Switching from async tasks to sync threads.

* Format script.

* Reading output through async events.

* Addressing PR comments

---------

Co-authored-by: Nikolay Borisenko <[email protected]>

Author: diemol

dotnet/src/webdriver/DriverProcessStartedEventArgs.cs

@@ -19,7 +19,6 @@
 
 using System;
 using System.Diagnostics;
-using System.IO;
 
 namespace OpenQA.Selenium;
 
@@ -41,31 +40,10 @@ public DriverProcessStartedEventArgs(Process driverProcess)
         }
 
         this.ProcessId = driverProcess.Id;
-        if (driverProcess.StartInfo.RedirectStandardOutput && !driverProcess.StartInfo.UseShellExecute)
-        {
-            this.StandardOutputStreamReader = driverProcess.StandardOutput;
-        }
-
-        if (driverProcess.StartInfo.RedirectStandardError && !driverProcess.StartInfo.UseShellExecute)
-        {
-            this.StandardErrorStreamReader = driverProcess.StandardError;
-        }
     }
 
     /// <summary>
     /// Gets the unique ID of the driver executable process.
     /// </summary>
     public int ProcessId { get; }
-
-    /// <summary>
-    /// Gets a <see cref="StreamReader"/> object that can be used to read the contents
-    /// printed to <c>stdout</c> by a driver service process.
-    /// </summary>
-    public StreamReader? StandardOutputStreamReader { get; }
-
-    /// <summary>
-    /// Gets a <see cref="StreamReader"/> object that can be used to read the contents
-    /// printed to <c>stderr</c> by a driver service process.
-    /// </summary>
-    public StreamReader? StandardErrorStreamReader { get; }
 }

dotnet/src/webdriver/DriverService.cs

@@ -26,6 +26,7 @@
 using System.Net;
 using System.Net.Http;
 using System.Threading.Tasks;
+using OpenQA.Selenium.Internal.Logging;
 
 namespace OpenQA.Selenium;
 
@@ -37,6 +38,8 @@ public abstract class DriverService : ICommandServer
     private bool isDisposed;
     private Process? driverServiceProcess;
 
+    private static readonly ILogger _logger = Log.GetLogger(typeof(DriverService));
+
     /// <summary>
     /// Initializes a new instance of the <see cref="DriverService"/> class.
     /// </summary>
@@ -243,6 +246,12 @@ public void Start()
         this.driverServiceProcess.StartInfo.UseShellExecute = false;
         this.driverServiceProcess.StartInfo.CreateNoWindow = this.HideCommandPromptWindow;
 
+        this.driverServiceProcess.StartInfo.RedirectStandardOutput = true;
+        this.driverServiceProcess.StartInfo.RedirectStandardError = true;
+
+        this.driverServiceProcess.OutputDataReceived += this.OnDriverProcessDataReceived;
+        this.driverServiceProcess.ErrorDataReceived += this.OnDriverProcessDataReceived;
+
         DriverProcessStartingEventArgs eventArgs = new DriverProcessStartingEventArgs(this.driverServiceProcess.StartInfo);
         this.OnDriverProcessStarting(eventArgs);
 
@@ -251,6 +260,9 @@ public void Start()
         DriverProcessStartedEventArgs processStartedEventArgs = new DriverProcessStartedEventArgs(this.driverServiceProcess);
         this.OnDriverProcessStarted(processStartedEventArgs);
 
+        this.driverServiceProcess.BeginOutputReadLine();
+        this.driverServiceProcess.BeginErrorReadLine();
+
         if (!serviceAvailable)
         {
             throw new WebDriverException($"Cannot start the driver service on {this.ServiceUrl}");
@@ -308,6 +320,23 @@ protected virtual void OnDriverProcessStarted(DriverProcessStartedEventArgs even
         this.DriverProcessStarted?.Invoke(this, eventArgs);
     }
 
+    /// <summary>
+    /// Handles the output and error data received from the driver process.
+    /// </summary>
+    /// <param name="sender">The sender of the event.</param>
+    /// <param name="args">The data received event arguments.</param>
+    /// <param name="isError">A value indicating whether the data received is from the error stream.</param>
+    protected virtual void OnDriverProcessDataReceived(object sender, DataReceivedEventArgs args)
+    {
+        if (string.IsNullOrEmpty(args.Data))
+            return;
+
+        if (_logger.IsEnabled(LogEventLevel.Trace))
+        {
+            _logger.Trace(args.Data);
+        }
+    }
+
     /// <summary>
     /// Stops the DriverService.
     /// </summary>

dotnet/src/webdriver/Firefox/FirefoxDriverService.cs

@@ -19,10 +19,10 @@
 
 using OpenQA.Selenium.Internal;
 using System;
+using System.Diagnostics;
 using System.Globalization;
 using System.IO;
 using System.Text;
-using System.Threading.Tasks;
 
 namespace OpenQA.Selenium.Firefox;
 
@@ -223,11 +223,11 @@ protected override string CommandLineArguments
     }
 
     /// <summary>
-    /// Handles the event when the driver service process is starting.
+    /// Called when the driver process is starting. This method sets up log file writing if a log path is specified.
     /// </summary>
     /// <param name="eventArgs">The event arguments containing information about the driver service process.</param>
     /// <remarks>
-    /// This method initializes a log writer if a log path is specified and redirects output streams to capture logs.
+    /// This method initializes a log writer if a log path is specified.
     /// </remarks>
     protected override void OnDriverProcessStarting(DriverProcessStartingEventArgs eventArgs)
     {
@@ -239,40 +239,37 @@ protected override void OnDriverProcessStarting(DriverProcessStartingEventArgs e
                 Directory.CreateDirectory(directory);
             }
 
-            // Initialize the log writer
             logWriter = new StreamWriter(this.LogPath, append: true) { AutoFlush = true };
-
-            // Configure process to redirect output
-            eventArgs.DriverServiceProcessStartInfo.RedirectStandardOutput = true;
-            eventArgs.DriverServiceProcessStartInfo.RedirectStandardError = true;
         }
 
         base.OnDriverProcessStarting(eventArgs);
     }
 
     /// <summary>
-    /// Handles the event when the driver process has started.
+    /// Handles the output and error data received from the driver process and sends it to the log writer if available.
     /// </summary>
-    /// <param name="eventArgs">The event arguments containing information about the started driver process.</param>
-    /// <remarks>
-    /// This method reads the output and error streams asynchronously and writes them to the log file if available.
-    /// </remarks>
-    protected override void OnDriverProcessStarted(DriverProcessStartedEventArgs eventArgs)
+    /// <param name="sender">The sender of the event.</param>
+    /// <param name="args">The data received event arguments.</param>
+    /// <param name="isError">A value indicating whether the data received is from the error stream.</param>
+    protected override void OnDriverProcessDataReceived(object sender, DataReceivedEventArgs args)
     {
-        if (logWriter == null) return;
-        if (eventArgs.StandardOutputStreamReader != null)
+        if (string.IsNullOrEmpty(args.Data))
+            return;
+
+        if (!string.IsNullOrEmpty(this.LogPath))
         {
-            _ = Task.Run(() => ReadStreamAsync(eventArgs.StandardOutputStreamReader));
+            if (logWriter != null)
+            {
+                logWriter.WriteLine(args.Data);
+            }
         }
-
-        if (eventArgs.StandardErrorStreamReader != null)
+        else
         {
-            _ = Task.Run(() => ReadStreamAsync(eventArgs.StandardErrorStreamReader));
+            base.OnDriverProcessDataReceived(sender, args);
         }
-
-        base.OnDriverProcessStarted(eventArgs);
     }
 
+
     /// <summary>
     /// Disposes of the resources used by the <see cref="FirefoxDriverService"/> instance.
     /// </summary>
@@ -372,24 +369,4 @@ private static string FirefoxDriverServiceFileName()
 
         return fileName;
     }
-
-    private async Task ReadStreamAsync(StreamReader reader)
-    {
-        try
-        {
-            string? line;
-            while ((line = await reader.ReadLineAsync()) != null)
-            {
-                if (logWriter != null)
-                {
-                    logWriter.WriteLine($"{DateTime.Now:yyyy-MM-dd HH:mm:ss.fff} {line}");
-                }
-            }
-        }
-        catch (Exception ex)
-        {
-            // Log or handle the exception appropriately
-            System.Diagnostics.Debug.WriteLine($"Error reading stream: {ex.Message}");
-        }
-    }
 }

dotnet/test/firefox/FirefoxDriverServiceTest.cs

@@ -17,25 +17,52 @@
 // under the License.
 // </copyright>
 
+using System;
+using System.Collections.Generic;
 using NUnit.Framework;
 using System.IO;
+using System.Linq;
+using OpenQA.Selenium.Internal.Logging;
 
 namespace OpenQA.Selenium.Firefox;
 
 [TestFixture]
-public class FirefoxDriverServiceTest : DriverTestFixture
+public class FirefoxDriverServiceTest
 {
+    private TestLogHandler testLogHandler;
+
+    private void ResetGlobalLog()
+    {
+        Log.SetLevel(LogEventLevel.Info);
+        Log.Handlers.Clear().Handlers.Add(new TextWriterHandler(Console.Error));
+    }
+
+    [SetUp]
+    public void SetUp()
+    {
+        ResetGlobalLog();
+
+        testLogHandler = new TestLogHandler();
+    }
+
+    [TearDown]
+    public void TearDown()
+    {
+        ResetGlobalLog();
+    }
+
     [Test]
     public void ShouldRedirectGeckoDriverLogsToFile()
     {
         FirefoxOptions options = new FirefoxOptions();
         string logPath = Path.GetTempFileName();
-        options.LogLevel = FirefoxDriverLogLevel.Trace;
+        options.LogLevel = FirefoxDriverLogLevel.Info;
 
         FirefoxDriverService service = FirefoxDriverService.CreateDefaultService();
         service.LogPath = logPath;
 
-        IWebDriver driver2 = new FirefoxDriver(service, options);
+        IWebDriver firefoxDriver = new FirefoxDriver(service, options);
+        firefoxDriver.Quit();
 
         try
         {
@@ -45,9 +72,44 @@ public void ShouldRedirectGeckoDriverLogsToFile()
         }
         finally
         {
-            driver2.Quit();
             File.Delete(logPath);
         }
     }
 
+    [Test]
+    public void ShouldRedirectGeckoDriverLogsToConsole()
+    {
+        Log.SetLevel(LogEventLevel.Trace).Handlers.Add(testLogHandler);
+        FirefoxOptions options = new FirefoxOptions();
+        options.LogLevel = FirefoxDriverLogLevel.Info;
+
+        FirefoxDriverService service = FirefoxDriverService.CreateDefaultService();
+
+        IWebDriver firefoxDriver = new FirefoxDriver(service, options);
+
+        try
+        {
+            Assert.That(testLogHandler.Events, Has.Count.AtLeast(1));
+            Assert.That(testLogHandler.Events.Any(e => e.Message.Contains("geckodriver")), Is.True);
+        }
+        finally
+        {
+            firefoxDriver.Quit();
+        }
+    }
+}
+
+class TestLogHandler : ILogHandler
+{
+    public ILogHandler Clone()
+    {
+        return this;
+    }
+
+    public void Handle(LogEvent logEvent)
+    {
+        Events.Add(logEvent);
+    }
+
+    public IList<LogEvent> Events { get; internal set; } = new List<LogEvent>();
 }