Skip to content

Conversation

nvborisenko
Copy link
Member

@nvborisenko nvborisenko commented Sep 25, 2025

User description

This is my experiments to resolve the #16245 (comment) issue.

💥 What does this PR do?

It allocates dedicated thread to listen to console process output immediately.


PR Type

Bug fix


Description

  • Replace async event-based output reading with dedicated threads

  • Convert synchronous service initialization to async pattern

  • Add comprehensive logging for service lifecycle debugging

  • Fix potential STD stream starvation issue in driver services


Diagram Walkthrough

flowchart LR
  A["Event-based async reading"] --> B["Dedicated thread reading"]
  C["Synchronous initialization"] --> D["Async initialization pattern"]
  E["Limited logging"] --> F["Enhanced debug logging"]
  B --> G["Prevents STD starvation"]
  D --> G
Loading

File Walkthrough

Relevant files
Bug fix
DriverService.cs
Core service threading and async refactor                               

dotnet/src/webdriver/DriverService.cs

  • Replace BeginOutputReadLine/BeginErrorReadLine with dedicated threads
  • Convert IsInitialized property to async method
  • Add comprehensive debug logging throughout service lifecycle
  • Update Start() method to be async with proper thread management
+159/-41
FirefoxDriverService.cs
Firefox service method signature update                                   

dotnet/src/webdriver/Firefox/FirefoxDriverService.cs

  • Update OnDriverProcessDataReceived signature to match base class
    changes
  • Remove sender and DataReceivedEventArgs parameters
+4/-4     
DriverServiceCommandExecutor.cs
Async service start integration                                                   

dotnet/src/webdriver/Remote/DriverServiceCommandExecutor.cs

  • Update service.Start() call to await async version
  • Add ConfigureAwait(false) for proper async handling
+1/-1     
ICommandServer.cs
Interface async method signature update                                   

dotnet/src/webdriver/Remote/ICommandServer.cs

  • Change Start() method signature from void to Task
  • Add System.Threading.Tasks using statement
+2/-1     

@selenium-ci selenium-ci added the C-dotnet .NET Bindings label Sep 25, 2025
Copy link
Contributor

PR Reviewer Guide 🔍

Here are some key observations to aid the review process:

🎫 Ticket compliance analysis 🔶

16245 - Partially compliant

Compliant requirements:

  • Address performance degradation related to STDIO starvation by replacing async event-based readers with dedicated threads.
  • Ensure driver service remains responsive by actively probing status and waiting for initialization.

Non-compliant requirements:

  • Restore performance comparable to v4.34.0 (cannot be proven by code alone).

Requires further human verification:

  • Benchmark parallel test performance vs 4.34.0 on Windows with multiple drivers.
  • Validate no regressions in service lifecycle (start/stop) across all supported drivers.
  • Confirm logging overhead does not impact performance in trace/debug levels under parallel load.
⏱️ Estimated effort to review: 4 🔵🔵🔵🔵⚪
🧪 No relevant tests
🔒 No security concerns identified
⚡ Recommended focus areas for review

API Change

Start() is now async Task and IsInitialized is async; verify all call sites and implementers (including ICommandServer and derived services) are updated to avoid deadlocks or missed awaits.

public async Task Start()
{
    if (this.driverServiceProcess != null)
    {
        return;
    }

    this.driverServiceProcess = new Process();

    if (this.DriverServicePath != null)
    {
        if (this.DriverServiceExecutableName is null)
        {
            throw new InvalidOperationException("If the driver service path is specified, the driver service executable name must be as well");
        }

        this.driverServiceProcess.StartInfo.FileName = Path.Combine(this.DriverServicePath, this.DriverServiceExecutableName);
    }
    else
    {
        this.driverServiceProcess.StartInfo.FileName = new DriverFinder(this.GetDefaultDriverOptions()).GetDriverPath();
    }

    this.driverServiceProcess.StartInfo.Arguments = this.CommandLineArguments;
    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);

    if (_logger.IsEnabled(LogEventLevel.Debug))
    {
        _logger.Debug("Starting driver service process");
    }

    // Important: Start the process and immediately begin reading the output and error streams to avoid IO deadlocks.
    this.driverServiceProcess.Start();
    //this.driverServiceProcess.BeginOutputReadLine();
    //this.driverServiceProcess.BeginErrorReadLine();

    if (_logger.IsEnabled(LogEventLevel.Trace))
    {
        // Capture a stable reference to the process to avoid races with Stop() nulling the field
        var proc = this.driverServiceProcess;

        _outputThread = new Thread(() =>
        {
            try
            {
                if (proc == null)
                {
                    return;
                }

                using (var reader = proc.StandardOutput)
                {
                    string? line;
                    while ((line = reader.ReadLine()) != null)
                    {
                        OnDriverProcessDataReceived(line);
                    }
                }
            }
            catch (ObjectDisposedException)
            {
                // Process or stream disposed during shutdown; ignore
            }
            catch (IOException)
            {
                // Stream closed; ignore
            }
        })
        {
            IsBackground = true,
            Name = "DriverService-stdout"
        };

        _errorThread = new Thread(() =>
        {
            try
            {
                if (proc == null)
                {
                    return;
                }

                using (var reader = proc.StandardError)
                {
                    string? line;
                    while ((line = reader.ReadLine()) != null)
                    {
                        OnDriverProcessDataReceived(line);
                    }
                }
            }
            catch (ObjectDisposedException)
            {
                // Process or stream disposed during shutdown; ignore
            }
            catch (IOException)
            {
                // Stream closed; ignore
            }
        })
        {
            IsBackground = true,
            Name = "DriverService-stderr"
        };

        _outputThread.Start();
        _errorThread.Start();
    }

    bool serviceAvailable = await this.WaitForServiceInitialization().ConfigureAwait(false);

    DriverProcessStartedEventArgs processStartedEventArgs = new DriverProcessStartedEventArgs(this.driverServiceProcess);
    this.OnDriverProcessStarted(processStartedEventArgs);

    if (!serviceAvailable)
    {
        throw new WebDriverException($"Cannot start the driver service on {this.ServiceUrl}");
    }

    if (_logger.IsEnabled(LogEventLevel.Debug))
    {
        _logger.Debug("Driver service process is started");
    }
}
Logging Overhead

Debug/Trace logging inside tight initialization loop and per-line output may significantly affect performance in parallel; consider throttling or reducing verbosity by default.

var sw = Stopwatch.StartNew();

bool isInitialized = false;
DateTime timeout = DateTime.Now.Add(this.InitializationTimeout);
while (!isInitialized && DateTime.Now < timeout)
{
    _logger.Debug("LOOP");
    // If the driver service process has exited, we can exit early.
    //if (!this.IsRunning)
    //{
    //    break;
    //}

    isInitialized = await this.IsInitialized().ConfigureAwait(false);
}

if (_logger.IsEnabled(LogEventLevel.Debug))
{
    _logger.Debug($"Driver service initialization status: {isInitialized} {sw.Elapsed}");
}
Thread Lifecycle

Reader threads are started only when Trace is enabled; when Trace is off, redirected streams still enabled but not read, risking deadlock/backpressure. Ensure threads always read when redirection is on.

if (_logger.IsEnabled(LogEventLevel.Debug))
{
    _logger.Debug("Starting driver service process");
}

// Important: Start the process and immediately begin reading the output and error streams to avoid IO deadlocks.
this.driverServiceProcess.Start();
//this.driverServiceProcess.BeginOutputReadLine();
//this.driverServiceProcess.BeginErrorReadLine();

if (_logger.IsEnabled(LogEventLevel.Trace))
{
    // Capture a stable reference to the process to avoid races with Stop() nulling the field
    var proc = this.driverServiceProcess;

    _outputThread = new Thread(() =>
    {
        try
        {
            if (proc == null)
            {
                return;
            }

            using (var reader = proc.StandardOutput)
            {
                string? line;
                while ((line = reader.ReadLine()) != null)
                {
                    OnDriverProcessDataReceived(line);
                }
            }
        }
        catch (ObjectDisposedException)
        {
            // Process or stream disposed during shutdown; ignore
        }
        catch (IOException)
        {
            // Stream closed; ignore
        }
    })
    {
        IsBackground = true,
        Name = "DriverService-stdout"
    };

    _errorThread = new Thread(() =>
    {
        try
        {
            if (proc == null)
            {
                return;
            }

            using (var reader = proc.StandardError)
            {
                string? line;
                while ((line = reader.ReadLine()) != null)
                {
                    OnDriverProcessDataReceived(line);
                }
            }
        }
        catch (ObjectDisposedException)
        {
            // Process or stream disposed during shutdown; ignore
        }
        catch (IOException)
        {
            // Stream closed; ignore
        }
    })
    {
        IsBackground = true,
        Name = "DriverService-stderr"
    };

    _outputThread.Start();
    _errorThread.Start();
}

Copy link
Contributor

PR Code Suggestions ✨

Explore these optional code suggestions:

CategorySuggestion                                                                                                                                    Impact
Possible issue
Unconditionally read process output streams

Move the creation and start of the output/error stream reader threads outside of
the conditional if (_logger.IsEnabled(LogEventLevel.Trace)) block to ensure they
always run and prevent potential deadlocks.

dotnet/src/webdriver/DriverService.cs [281-352]

-if (_logger.IsEnabled(LogEventLevel.Trace))
+// Capture a stable reference to the process to avoid races with Stop() nulling the field
+var proc = this.driverServiceProcess;
+
+_outputThread = new Thread(() =>
 {
-    // Capture a stable reference to the process to avoid races with Stop() nulling the field
-    var proc = this.driverServiceProcess;
+    try
+    {
+        if (proc == null)
+        {
+            return;
+        }
 
-    _outputThread = new Thread(() =>
-    {
-        try
+        using (var reader = proc.StandardOutput)
         {
-            if (proc == null)
+            string? line;
+            while ((line = reader.ReadLine()) != null)
             {
-                return;
-            }
-
-            using (var reader = proc.StandardOutput)
-            {
-                string? line;
-                while ((line = reader.ReadLine()) != null)
-                {
-                    OnDriverProcessDataReceived(line);
-                }
+                OnDriverProcessDataReceived(line);
             }
         }
-        catch (ObjectDisposedException)
+    }
+    catch (ObjectDisposedException)
+    {
+        // Process or stream disposed during shutdown; ignore
+    }
+    catch (IOException)
+    {
+        // Stream closed; ignore
+    }
+})
+{
+    IsBackground = true,
+    Name = "DriverService-stdout"
+};
+
+_errorThread = new Thread(() =>
+{
+    try
+    {
+        if (proc == null)
         {
-            // Process or stream disposed during shutdown; ignore
+            return;
         }
-        catch (IOException)
+
+        using (var reader = proc.StandardError)
         {
-            // Stream closed; ignore
-        }
-    })
-    {
-        IsBackground = true,
-        Name = "DriverService-stdout"
-    };
-
-    _errorThread = new Thread(() =>
-    {
-        try
-        {
-            if (proc == null)
+            string? line;
+            while ((line = reader.ReadLine()) != null)
             {
-                return;
-            }
-
-            using (var reader = proc.StandardError)
-            {
-                string? line;
-                while ((line = reader.ReadLine()) != null)
-                {
-                    OnDriverProcessDataReceived(line);
-                }
+                OnDriverProcessDataReceived(line);
             }
         }
-        catch (ObjectDisposedException)
-        {
-            // Process or stream disposed during shutdown; ignore
-        }
-        catch (IOException)
-        {
-            // Stream closed; ignore
-        }
-    })
+    }
+    catch (ObjectDisposedException)
     {
-        IsBackground = true,
-        Name = "DriverService-stderr"
-    };
+        // Process or stream disposed during shutdown; ignore
+    }
+    catch (IOException)
+    {
+        // Stream closed; ignore
+    }
+})
+{
+    IsBackground = true,
+    Name = "DriverService-stderr"
+};
 
-    _outputThread.Start();
-    _errorThread.Start();
-}
+_outputThread.Start();
+_errorThread.Start();
  • Apply / Chat
Suggestion importance[1-10]: 10

__

Why: The suggestion correctly identifies a critical bug where the process output stream reading, intended to prevent deadlocks, is only activated when trace logging is enabled, defeating the main purpose of the PR.

High
Exit early if process terminates

Restore the if (!this.IsRunning) check inside the WaitForServiceInitialization
loop to exit early if the driver process terminates unexpectedly.

dotnet/src/webdriver/DriverService.cs [524-534]

 while (!isInitialized && DateTime.Now < timeout)
 {
     _logger.Debug("LOOP");
     // If the driver service process has exited, we can exit early.
-    //if (!this.IsRunning)
-    //{
-    //    break;
-    //}
+    if (!this.IsRunning)
+    {
+        break;
+    }
 
     isInitialized = await this.IsInitialized().ConfigureAwait(false);
 }
  • Apply / Chat
Suggestion importance[1-10]: 7

__

Why: The suggestion correctly identifies that commenting out the !this.IsRunning check is a regression, as it prevents an early exit from the initialization loop if the driver process terminates, thus delaying failure detection.

Medium
  • More

/// Gets a value indicating whether the service is responding to HTTP requests.
/// </summary>
protected virtual bool IsInitialized
protected virtual async Task<bool> IsInitialized()
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I had that PR to make this async that got delayed to v5 over concerns of breaking changes: #15246

If we are OK updating it now, I’d like to get that PR in and expand this solution on top of that one.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No, this doesn't resolve the issue. What I see: as soon as we dedicate new thread just to listen to console output, seems it works fine.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants