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 include http headers in internal logs #14546

Merged
merged 3 commits into from
Sep 28, 2024

Conversation

nvborisenko
Copy link
Member

@nvborisenko nvborisenko commented Sep 28, 2024

User description

Description

Before:

    22:28:10.657 DEBUG HttpCommandExecutor: Executing command: [1e74cb76431bed9eb5231b6fa0e06456]: get {"url":"http://localhost:63133/common/temp/page13039830558350188602.html"}
22:28:10.659 TRACE HttpCommandExecutor: >> Method: POST, RequestUri: 'http://localhost:63135/session/1e74cb76431bed9eb5231b6fa0e06456/url', Version: 1.1, Content: System.Net.Http.ByteArrayContent, Headers:
{
  Accept: application/json; charset=utf-8
  User-Agent: selenium/4.0.0+7d1d0e09fe91ec4b38926b12167fa5ce0007e289
  User-Agent: (.net windows)
  Content-Type: application/json; charset=utf-8
  Content-Length: 74
}
{"url":"http://localhost:63133/common/temp/page13039830558350188602.html"}
22:28:10.720 TRACE HttpCommandExecutor: << StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
{
  Cache-Control: no-cache
  Content-Length: 14
  Content-Type: application/json; charset=utf-8
}
22:28:10.720 DEBUG HttpCommandExecutor: Response: ( Success: )
22:28:10.731 DEBUG HttpCommandExecutor: Executing command: [1e74cb76431bed9eb5231b6fa0e06456]: findElement {"using":"css selector","value":"#alert"}
22:28:10.732 TRACE HttpCommandExecutor: >> Method: POST, RequestUri: 'http://localhost:63135/session/1e74cb76431bed9eb5231b6fa0e06456/element', Version: 1.1, Content: System.Net.Http.ByteArrayContent, Headers:
{
  Accept: application/json; charset=utf-8
  User-Agent: selenium/4.0.0+7d1d0e09fe91ec4b38926b12167fa5ce0007e289
  User-Agent: (.net windows)
  Content-Type: application/json; charset=utf-8
  Content-Length: 41
}
{"using":"css selector","value":"#alert"}
22:28:10.745 TRACE HttpCommandExecutor: << StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
{
  Cache-Control: no-cache
  Content-Length: 125
  Content-Type: application/json; charset=utf-8
}
22:28:10.745 DEBUG HttpCommandExecutor: Response: ( Success: System.Collections.Generic.Dictionary`2[System.String,System.Object])
22:28:10.747 DEBUG HttpCommandExecutor: Executing command: [1e74cb76431bed9eb5231b6fa0e06456]: clickElement {"id":"f.F6B893528C9CA515BB4C7B4302BDC6DD.d.C5E9C8115018CF29FB46019A427AFCE0.e.2"}
22:28:10.747 TRACE HttpCommandExecutor: >> Method: POST, RequestUri: 'http://localhost:63135/session/1e74cb76431bed9eb5231b6fa0e06456/element/f.F6B893528C9CA515BB4C7B4302BDC6DD.d.C5E9C8115018CF29FB46019A427AFCE0.e.2/click', Version: 1.1, Content: System.Net.Http.ByteArrayContent, Headers:
{
  Accept: application/json; charset=utf-8
  User-Agent: selenium/4.0.0+7d1d0e09fe91ec4b38926b12167fa5ce0007e289
  User-Agent: (.net windows)
  Content-Type: application/json; charset=utf-8
  Content-Length: 2
}
{}
22:28:10.792 TRACE HttpCommandExecutor: << StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
{
  Cache-Control: no-cache
  Content-Length: 14
  Content-Type: application/json; charset=utf-8
}
22:28:10.793 DEBUG HttpCommandExecutor: Response: ( Success: )
22:28:10.794 DEBUG HttpCommandExecutor: Executing command: [1e74cb76431bed9eb5231b6fa0e06456]: getAlertText {}
22:28:10.794 TRACE HttpCommandExecutor: >> Method: GET, RequestUri: 'http://localhost:63135/session/1e74cb76431bed9eb5231b6fa0e06456/alert/text', Version: 1.1, Content: <null>, Headers:
{
  Cache-Control: no-cache
  User-Agent: selenium/4.0.0+7d1d0e09fe91ec4b38926b12167fa5ce0007e289
  User-Agent: (.net windows)
  Accept: application/json
  Accept: image/png
}
22:28:10.794 TRACE HttpCommandExecutor: << StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
{
  Cache-Control: no-cache
  Content-Length: 18
  Content-Type: application/json; charset=utf-8
}
22:28:10.801 DEBUG HttpCommandExecutor: Response: ( Success: cheese)
22:28:10.801 DEBUG HttpCommandExecutor: Executing command: [1e74cb76431bed9eb5231b6fa0e06456]: dismissAlert {}
22:28:10.802 TRACE HttpCommandExecutor: >> Method: POST, RequestUri: 'http://localhost:63135/session/1e74cb76431bed9eb5231b6fa0e06456/alert/dismiss', Version: 1.1, Content: System.Net.Http.ByteArrayContent, Headers:
{
  Accept: application/json; charset=utf-8
  User-Agent: selenium/4.0.0+7d1d0e09fe91ec4b38926b12167fa5ce0007e289
  User-Agent: (.net windows)
  Content-Type: application/json; charset=utf-8
  Content-Length: 2
}
{}
22:28:10.804 TRACE HttpCommandExecutor: << StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
{
  Cache-Control: no-cache
  Content-Length: 14
  Content-Type: application/json; charset=utf-8
}
22:28:10.804 DEBUG HttpCommandExecutor: Response: ( Success: )
22:28:10.812 DEBUG HttpCommandExecutor: Executing command: [1e74cb76431bed9eb5231b6fa0e06456]: getAlertText {}
22:28:10.812 TRACE HttpCommandExecutor: >> Method: GET, RequestUri: 'http://localhost:63135/session/1e74cb76431bed9eb5231b6fa0e06456/alert/text', Version: 1.1, Content: <null>, Headers:
{
  Cache-Control: no-cache
  User-Agent: selenium/4.0.0+7d1d0e09fe91ec4b38926b12167fa5ce0007e289
  User-Agent: (.net windows)
  Accept: application/json
  Accept: image/png
}
22:28:10.813 TRACE HttpCommandExecutor: << StatusCode: 404, ReasonPhrase: 'Not Found', Version: 1.1, Content: System.Net.Http.HttpConnectionResponseContent, Headers:
{
  Cache-Control: no-cache
  Content-Length: 961
  Content-Type: application/json; charset=utf-8
}
{"value":{"error":"no such alert","message":"no such alert\n  (Session info: chrome=129.0.6668.60)","stacktrace":"\tGetHandleVerifier [0x00007FF77662B125+29573]\n\t(No symbol) [0x00007FF77659FF50]\n\t(No symbol) [0x00007FF77645B519]\n\t(No symbol) [0x00007FF7764463A4]\n\t(No symbol) [0x00007FF77646EB81]\n\t(No symbol) [0x00007FF77647FEA7]\n\t(No symbol) [0x00007FF7764D73AD]\n\t(No symbol) [0x00007FF77647FD25]\n\t(No symbol) [0x00007FF7764D70A3]\n\t(No symbol) [0x00007FF7764A12DF]\n\t(No symbol) [0x00007FF7764A2441]\n\tGetHandleVerifier [0x00007FF77695C76D+3377613]\n\tGetHandleVerifier [0x00007FF7769A7B67+3685831]\n\tGetHandleVerifier [0x00007FF77699CF8B+3641835]\n\tGetHandleVerifier [0x00007FF7766EB2A6+816390]\n\t(No symbol) [0x00007FF7765AB25F]\n\t(No symbol) [0x00007FF7765A7084]\n\t(No symbol) [0x00007FF7765A7220]\n\t(No symbol) [0x00007FF77659607F]\n\tBaseThreadInitThunk [0x00007FF83964257D+29]\n\tRtlUserThreadStart [0x00007FF83AC8AF28+40]\n"}}
22:28:10.815 DEBUG HttpCommandExecutor: Response: ( NoAlertPresent: System.Collections.Generic.Dictionary`2[System.String,System.Object])

After:
22:25:36.208 DEBUG HttpCommandExecutor: Executing command: [b3982ee404c0e5616649ac25dd1d79bc]: get {"url":"http://localhost:63043/common/temp/page4449485843760331092.html"} 22:25:36.210 TRACE HttpCommandExecutor: >> POST RequestUri: http://localhost:63045/session/b3982ee404c0e5616649ac25dd1d79bc/url, Content: System.Net.Http.ByteArrayContent, Headers: 2 {"url":"http://localhost:63043/common/temp/page4449485843760331092.html"} 22:25:36.256 TRACE HttpCommandExecutor: << StatusCodde: 200, ReasonPhrase: OK, Content: System.Net.Http.HttpConnectionResponseContent, Headers: 1 22:25:36.256 DEBUG HttpCommandExecutor: Response: ( Success: ) 22:25:36.266 DEBUG HttpCommandExecutor: Executing command: [b3982ee404c0e5616649ac25dd1d79bc]: findElement {"using":"css selector","value":"#alert"} 22:25:36.267 TRACE HttpCommandExecutor: >> POST RequestUri: http://localhost:63045/session/b3982ee404c0e5616649ac25dd1d79bc/element, Content: System.Net.Http.ByteArrayContent, Headers: 2 {"using":"css selector","value":"#alert"} 22:25:36.303 TRACE HttpCommandExecutor: << StatusCodde: 200, ReasonPhrase: OK, Content: System.Net.Http.HttpConnectionResponseContent, Headers: 1 22:25:36.303 DEBUG HttpCommandExecutor: Response: ( Success: System.Collections.Generic.Dictionary`2[System.String,System.Object]) 22:25:36.304 DEBUG HttpCommandExecutor: Executing command: [b3982ee404c0e5616649ac25dd1d79bc]: clickElement {"id":"f.E17E54A357AA49FBDFA2B6AEB0509871.d.F26ABC8BFDB71F13D70157ABA1E035D5.e.2"} 22:25:36.305 TRACE HttpCommandExecutor: >> POST RequestUri: http://localhost:63045/session/b3982ee404c0e5616649ac25dd1d79bc/element/f.E17E54A357AA49FBDFA2B6AEB0509871.d.F26ABC8BFDB71F13D70157ABA1E035D5.e.2/click, Content: System.Net.Http.ByteArrayContent, Headers: 2 {} 22:25:36.372 TRACE HttpCommandExecutor: << StatusCodde: 200, ReasonPhrase: OK, Content: System.Net.Http.HttpConnectionResponseContent, Headers: 1 22:25:36.373 DEBUG HttpCommandExecutor: Response: ( Success: ) 22:25:36.374 DEBUG HttpCommandExecutor: Executing command: [b3982ee404c0e5616649ac25dd1d79bc]: getAlertText {} 22:25:36.377 TRACE HttpCommandExecutor: >> GET RequestUri: http://localhost:63045/session/b3982ee404c0e5616649ac25dd1d79bc/alert/text, Content: , Headers: 3 22:25:36.382 TRACE HttpCommandExecutor: << StatusCodde: 200, ReasonPhrase: OK, Content: System.Net.Http.HttpConnectionResponseContent, Headers: 1 22:25:36.393 DEBUG HttpCommandExecutor: Response: ( Success: cheese) 22:25:36.393 DEBUG HttpCommandExecutor: Executing command: [b3982ee404c0e5616649ac25dd1d79bc]: dismissAlert {} 22:25:36.393 TRACE HttpCommandExecutor: >> POST RequestUri: http://localhost:63045/session/b3982ee404c0e5616649ac25dd1d79bc/alert/dismiss, Content: System.Net.Http.ByteArrayContent, Headers: 2 {} 22:25:36.396 TRACE HttpCommandExecutor: << StatusCodde: 200, ReasonPhrase: OK, Content: System.Net.Http.HttpConnectionResponseContent, Headers: 1 22:25:36.396 DEBUG HttpCommandExecutor: Response: ( Success: ) 22:25:36.405 DEBUG HttpCommandExecutor: Executing command: [b3982ee404c0e5616649ac25dd1d79bc]: getAlertText {} 22:25:36.406 TRACE HttpCommandExecutor: >> GET RequestUri: http://localhost:63045/session/b3982ee404c0e5616649ac25dd1d79bc/alert/text, Content: , Headers: 3 22:25:36.408 TRACE HttpCommandExecutor: << StatusCodde: 404, ReasonPhrase: Not Found, Content: System.Net.Http.HttpConnectionResponseContent, Headers: 1 {"value":{"error":"no such alert","message":"no such alert\n (Session info: chrome=129.0.6668.60)","stacktrace":"\tGetHandleVerifier [0x00007FF77662B125+29573]\n\t(No symbol) [0x00007FF77659FF50]\n\t(No symbol) [0x00007FF77645B519]\n\t(No symbol) [0x00007FF7764463A4]\n\t(No symbol) [0x00007FF77646EB81]\n\t(No symbol) [0x00007FF77647FEA7]\n\t(No symbol) [0x00007FF7764D73AD]\n\t(No symbol) [0x00007FF77647FD25]\n\t(No symbol) [0x00007FF7764D70A3]\n\t(No symbol) [0x00007FF7764A12DF]\n\t(No symbol) [0x00007FF7764A2441]\n\tGetHandleVerifier [0x00007FF77695C76D+3377613]\n\tGetHandleVerifier [0x00007FF7769A7B67+3685831]\n\tGetHandleVerifier [0x00007FF77699CF8B+3641835]\n\tGetHandleVerifier [0x00007FF7766EB2A6+816390]\n\t(No symbol) [0x00007FF7765AB25F]\n\t(No symbol) [0x00007FF7765A7084]\n\t(No symbol) [0x00007FF7765A7220]\n\t(No symbol) [0x00007FF77659607F]\n\tBaseThreadInitThunk [0x00007FF83964257D+29]\n\tRtlUserThreadStart [0x00007FF83AC8AF28+40]\n"}} 22:25:36.413 DEBUG HttpCommandExecutor: Response: ( NoAlertPresent: System.Collections.Generic.Dictionary`2[System.String,System.Object])`

Motivation and Context

Simplify internal logs reading. It is better when considering security aspects when auth token is sent via http header.

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

  • Enhanced the logging mechanism in HttpCommandExecutor to exclude detailed HTTP headers from internal logs.
  • Updated the log format to include the count of headers instead of their full details, reducing verbosity.
  • Improved clarity of log messages by specifying key request and response attributes such as RequestUri, Content, and StatusCode.

Changes walkthrough 📝

Relevant files
Enhancement
HttpCommandExecutor.cs
Simplify HTTP request and response logging                             

dotnet/src/webdriver/Remote/HttpCommandExecutor.cs

  • Modified logging format for HTTP requests and responses.
  • Removed detailed HTTP headers from internal logs.
  • Added count of headers instead of full header details.
  • +3/-2     

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

    Copy link
    Contributor

    PR Reviewer Guide 🔍

    ⏱️ Estimated effort to review: 2 🔵🔵⚪⚪⚪
    🧪 No relevant tests
    🔒 No security concerns identified
    ⚡ Key issues to review

    Possible Typo
    There's a typo in the word "StatusCode" in the response logging format string.

    Potential Information Loss
    The new logging format only includes the count of headers, which might lead to loss of important debugging information.

    Copy link
    Contributor

    qodo-merge-pro bot commented Sep 28, 2024

    PR Code Suggestions ✨

    Explore these optional code suggestions:

    CategorySuggestion                                                                                                                                    Score
    Possible issue
    ✅ Correct the spelling of 'StatusCode' in the log message

    The StatusCodde in the response log message is misspelled. Correct it to StatusCode
    to ensure accurate logging and avoid confusion.

    dotnet/src/webdriver/Remote/HttpCommandExecutor.cs [434]

    -responseLogMessageBuilder.AppendFormat("<< StatusCodde: {0}, ReasonPhrase: {1}, Content: {2}, Headers: {3}", (int)response.StatusCode, response.ReasonPhrase, response.Content, response.Headers?.Count());
    +responseLogMessageBuilder.AppendFormat("<< StatusCode: {0}, ReasonPhrase: {1}, Content: {2}, Headers: {3}", (int)response.StatusCode, response.ReasonPhrase, response.Content, response.Headers?.Count());

    [Suggestion has been applied]

    Suggestion importance[1-10]: 9

    Why: Correcting the spelling of 'StatusCode' is crucial for accurate logging and preventing confusion, making this a high-impact fix.

    9
    ✅ Add null checks for request properties to prevent potential exceptions

    Consider adding null checks for request.RequestUri and request.Content to avoid
    potential NullReferenceExceptions. While these are unlikely to be null, adding
    checks can improve the robustness of the code.

    dotnet/src/webdriver/Remote/HttpCommandExecutor.cs [421]

    -requestLogMessageBuilder.AppendFormat(">> {0} RequestUri: {1}, Content: {2}, Headers: {3}", request.Method, request.RequestUri, request.Content, request.Headers?.Count());
    +requestLogMessageBuilder.AppendFormat(">> {0} RequestUri: {1}, Content: {2}, Headers: {3}", 
    +    request.Method, 
    +    request.RequestUri?.ToString() ?? "null", 
    +    request.Content?.ToString() ?? "null", 
    +    request.Headers?.Count());

    [Suggestion has been applied]

    Suggestion importance[1-10]: 6

    Why: Adding null checks increases the robustness of the code by preventing potential NullReferenceExceptions, although the likelihood of these properties being null is low.

    6
    Best practice
    Use nameof operator for property names in log messages to improve maintainability

    Consider using nameof(response.StatusCode) instead of hardcoding the property name
    as a string. This approach is more maintainable and refactoring-friendly, as it will
    automatically update if the property name changes in the future.

    dotnet/src/webdriver/Remote/HttpCommandExecutor.cs [434]

    -responseLogMessageBuilder.AppendFormat("<< StatusCodde: {0}, ReasonPhrase: {1}, Content: {2}, Headers: {3}", (int)response.StatusCode, response.ReasonPhrase, response.Content, response.Headers?.Count());
    +responseLogMessageBuilder.AppendFormat("<< {0}: {1}, {2}: {3}, {4}: {5}, {6}: {7}", 
    +    nameof(response.StatusCode), (int)response.StatusCode, 
    +    nameof(response.ReasonPhrase), response.ReasonPhrase, 
    +    nameof(response.Content), response.Content, 
    +    nameof(response.Headers), response.Headers?.Count());
    • Apply this suggestion
    Suggestion importance[1-10]: 8

    Why: Using the nameof operator enhances maintainability by ensuring that property names in log messages automatically update if the code changes, reducing the risk of errors during refactoring.

    8
    Enhancement
    Use string interpolation instead of string formatting for improved readability

    Consider using string interpolation instead of AppendFormat for better readability
    and maintainability. String interpolation allows for a more natural way to embed
    expressions in string literals.

    dotnet/src/webdriver/Remote/HttpCommandExecutor.cs [421]

    -requestLogMessageBuilder.AppendFormat(">> {0} RequestUri: {1}, Content: {2}, Headers: {3}", request.Method, request.RequestUri, request.Content, request.Headers?.Count());
    +requestLogMessageBuilder.Append($">> {request.Method} RequestUri: {request.RequestUri}, Content: {request.Content}, Headers: {request.Headers?.Count()}");
    • Apply this suggestion
    Suggestion importance[1-10]: 7

    Why: The suggestion to use string interpolation improves readability and maintainability, making the code easier to understand and modify in the future.

    7

    💡 Need additional feedback ? start a PR chat

    Co-authored-by: codiumai-pr-agent-pro[bot] <151058649+codiumai-pr-agent-pro[bot]@users.noreply.github.com>
    Co-authored-by: codiumai-pr-agent-pro[bot] <151058649+codiumai-pr-agent-pro[bot]@users.noreply.github.com>
    @nvborisenko
    Copy link
    Member Author

    Failed CI is not related to the changes, thx @nvborisenko

    @nvborisenko nvborisenko merged commit 0cd8bbc into SeleniumHQ:trunk Sep 28, 2024
    8 of 10 checks passed
    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