Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[dotnet] Don't write trace log message when waiting until driver service is initialized #14557

Merged

Conversation

nvborisenko
Copy link
Member

@nvborisenko nvborisenko commented Oct 3, 2024

User description

On CI execution we see a lot of exceptions logged to output. Given that timeout is 5 seconds only, it is good just to suppress these exceptions even in internal logs.

Motivation and Context

In internal logs output we see:

Starting ChromeDriver 129.0.6668.89 (951c0b97221f8d4ba37cf97d324505c832251cf9-refs/branch-heads/6668@{#1503}) on port 33711
Only local connections are allowed.
Please see https://chromedriver.chromium.org/security-considerations for suggestions on keeping ChromeDriver safe.
ChromeDriver was started successfully on port 33711.
=> OpenQA.Selenium.DevTools.DevToolsNetworkTest
14:07:49.693 TRACE DriverService: System.Net.Http.HttpRequestException: Connection refused (localhost:33711)
 ---> System.Net.Sockets.SocketException (111): Connection refused
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
   at System.Net.Sockets.Socket.<ConnectAsync>g__WaitForConnectWithCancellation|285_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.ConnectToTcpHostAsync(String host, Int32 port, HttpRequestMessage initialRequest, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpConnectionPool.ConnectToTcpHostAsync(String host, Int32 port, HttpRequestMessage initialRequest, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.ConnectAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.CreateHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.AddHttp11ConnectionAsync(QueueItem queueItem)
   at System.Threading.Tasks.TaskCompletionSourceWithCancellation`1.WaitWithCancellationAsync(CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at OpenQA.Selenium.DriverService.<>c__DisplayClass51_1.<<get_IsInitialized>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at OpenQA.Selenium.DriverService.get_IsInitialized()
14:07:49.759 DEBUG HttpCommandExecutor: Executing command: []: newSession {"capabilities":{"firstMatch":[{"browserName":"chrome","browserVersion":"129","goog:chromeOptions":{"args":["--no-sandbox","--disable-dev-shm-usage"],"binary":"external/_main~pin_browsers_extension~linux_chrome/chrome-linux64/chrome"}}]}}
14:07:49.770 TRACE HttpCommandExecutor: >> POST RequestUri: http://localhost:33711/session, Content: System.Net.Http.ByteArrayContent, Headers: 2
{"capabilities":{"firstMatch":[{"browserName":"chrome","browserVersion":"129","goog:chromeOptions":{"args":["--no-sandbox","--disable-dev-shm-usage"],"binary":"external/_main~pin_browsers_extension~linux_chrome/chrome-linux64/chrome"}}]}}
14:07:50.644 TRACE HttpCommandExecutor: << StatusCode: 200, ReasonPhrase: OK, Content: System.Net.Http.HttpConnectionResponseContent, Headers: 1
14:07:50.654 DEBUG HttpCommandExecutor: Response: (8595a7fcc69f3c9a13e891be7132dbe1 Success: System.Collections.Generic.Dictionary`2[System.String,System.Object])
=> OpenQA.Selenium.DevTools.DevToolsNetworkTest.ByPassServiceWorker
14:07:51.017 DEBUG HttpCommandExecutor: Executing command: [8595a7fcc69f3c9a13e891be7132dbe1]: quit {}
14:07:51.018 TRACE HttpCommandExecutor: >> DELETE RequestUri: http://localhost:33711/session/8595a7fcc69f3c9a13e891be7132dbe1, Content: null, Headers: 2
14:07:51.071 TRACE HttpCommandExecutor: << StatusCode: 200, ReasonPhrase: OK, Content: System.Net.Http.HttpConnectionResponseContent, Headers: 1
14:07:51.071 DEBUG HttpCommandExecutor: Response: ( Success: )
=> OpenQA.Selenium.DevTools.DevToolsNetworkTest.EmulateNetworkConditionOffline
14:07:51.105 TRACE DriverService: System.Net.Http.HttpRequestException: Connection refused (localhost:44883)
 ---> System.Net.Sockets.SocketException (111): Connection refused
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
   at System.Net.Sockets.Socket.<ConnectAsync>g__WaitForConnectWithCancellation|285_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.ConnectToTcpHostAsync(String host, Int32 port, HttpRequestMessage initialRequest, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpConnectionPool.ConnectToTcpHostAsync(String host, Int32 port, HttpRequestMessage initialRequest, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.ConnectAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.CreateHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.AddHttp11ConnectionAsync(QueueItem queueItem)
   at System.Threading.Tasks.TaskCompletionSourceWithCancellation`1.WaitWithCancellationAsync(CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at OpenQA.Selenium.DriverService.<>c__DisplayClass51_1.<<get_IsInitialized>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at OpenQA.Selenium.DriverService.get_IsInitialized()
14:07:51.108 TRACE DriverService: System.Net.Http.HttpRequestException: Connection refused (localhost:44883)
 ---> System.Net.Sockets.SocketException (111): Connection refused
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken)
   at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token)
   at System.Net.Sockets.Socket.<ConnectAsync>g__WaitForConnectWithCancellation|285_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.ConnectToTcpHostAsync(String host, Int32 port, HttpRequestMessage initialRequest, Boolean async, CancellationToken cancellationToken)
   --- End of inner exception stack trace ---
   at System.Net.Http.HttpConnectionPool.ConnectToTcpHostAsync(String host, Int32 port, HttpRequestMessage initialRequest, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.ConnectAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.CreateHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.AddHttp11ConnectionAsync(QueueItem queueItem)
   at System.Threading.Tasks.TaskCompletionSourceWithCancellation`1.WaitWithCancellationAsync(CancellationToken cancellationToken)
   at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken)
   at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
   at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts, CancellationTokenSource pendingRequestsCts, CancellationToken originalCancellationToken)
   at OpenQA.Selenium.DriverService.<>c__DisplayClass51_1.<<get_IsInitialized>b__0>d.MoveNext()
--- End of stack trace from previous location ---
   at OpenQA.Selenium.DriverService.get_IsInitialized()

Types of changes

  • Bug fix (non-breaking change which fixes an issue)
  • New feature (non-breaking change which adds functionality)
  • Breaking change (fix or feature that would cause existing functionality to change)

Checklist

  • I have read the contributing document.
  • My change requires a change to the documentation.
  • I have updated the documentation accordingly.
  • I have added tests to cover my changes.
  • All new and existing tests passed.

PR Type

enhancement


Description

  • Removed trace logging of exceptions when waiting for the driver service to initialize, reducing unnecessary log output.
  • Deleted the logger initialization and the condition checking if trace logging is enabled.
  • Added a comment to clarify that exceptions during initialization are expected and should not be logged.

Changes walkthrough 📝

Relevant files
Enhancement
DriverService.cs
Suppress trace logging for driver service initialization exceptions

dotnet/src/webdriver/DriverService.cs

  • Removed trace logging for exceptions during driver service
    initialization.
  • Deleted the logger initialization and trace log condition.
  • Improved code clarity by commenting on the expected nature of
    exceptions.
  • +1/-6     

    💡 PR-Agent usage: Comment /help "your question" on any pull request to receive relevant information

    …ice is initialized
    
    On CI execution we see a lot of exceptions logged to output. Given that timeout is 5 seconds only, it is good just to suppress these exceptions even in internal logs.
    Copy link
    Contributor

    qodo-merge-pro bot commented Oct 3, 2024

    PR Reviewer Guide 🔍

    Here are some key observations to aid the review process:

    ⏱️ Estimated effort to review: 2 🔵🔵⚪⚪⚪
    🧪 No relevant tests
    🔒 No security concerns identified
    ⚡ Recommended focus areas for review

    Error Handling
    The removal of exception logging might make it harder to debug issues if they occur in production.

    Code Comment
    The new comment on line 239 contains a typo: "noothing" should be "nothing".

    Copy link
    Contributor

    qodo-merge-pro bot commented Oct 3, 2024

    PR Code Suggestions ✨

    Explore these optional code suggestions:

    CategorySuggestion                                                                                                                                    Score
    Best practice
    Use more specific exception types in the catch block

    Consider using a more specific exception type instead of the general Exception in
    the catch block. This can make the error handling more precise and easier to
    understand.

    dotnet/src/webdriver/DriverService.cs [237]

    -catch (Exception ex) when (ex is HttpRequestException || ex is TaskCanceledException)
    +catch (HttpRequestException ex)
    +{
    +    // The exception is expected, meaning driver service is not initialized
    +}
    +catch (TaskCanceledException ex)
    +{
    +    // The exception is expected, meaning driver service is not initialized
    +}
    • Apply this suggestion
    Suggestion importance[1-10]: 9

    Why: Using more specific exception types in the catch block improves the precision and clarity of error handling, aligning with best practices. This change makes the code easier to understand and maintain.

    9
    Correct a typo in the comment

    Fix the typo in the comment "do noothing" to "do nothing" for better code
    readability and professionalism.

    dotnet/src/webdriver/DriverService.cs [239]

    -// do noothing: the exception is expected, meaning driver service is not initialized
    +// do nothing: the exception is expected, meaning driver service is not initialized
    • Apply this suggestion
    Suggestion importance[1-10]: 8

    Why: Fixing the typo in the comment improves code readability and professionalism. It is a straightforward correction that enhances the clarity of the code documentation.

    8
    Enhancement
    Add a debug log message for exceptions during driver service initialization

    Consider adding a debug log message to provide more information about the exception.
    This can help with troubleshooting without adding unnecessary noise to the trace
    logs.

    dotnet/src/webdriver/DriverService.cs [237-240]

     catch (Exception ex) when (ex is HttpRequestException || ex is TaskCanceledException)
     {
    -    // do noothing: the exception is expected, meaning driver service is not initialized
    +    // The exception is expected, meaning driver service is not initialized
    +    Debug.WriteLine($"Driver service initialization in progress: {ex.GetType().Name}");
     }
    • Apply this suggestion
    Suggestion importance[1-10]: 7

    Why: Adding a debug log message can aid in troubleshooting without cluttering trace logs, which aligns with the PR's goal of removing unnecessary trace logging. This suggestion enhances the code's maintainability and debugging capability.

    7

    💡 Need additional feedback ? start a PR chat

    @nvborisenko
    Copy link
    Member Author

    @nvborisenko nvborisenko merged commit 1216ed9 into SeleniumHQ:trunk Oct 3, 2024
    8 of 10 checks passed
    @nvborisenko nvborisenko deleted the dotnet-logging-driverinitialized branch October 3, 2024 17:50
    Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
    Projects
    None yet
    Development

    Successfully merging this pull request may close these issues.

    1 participant