govin
govin

Reputation: 6733

Logging request/response messages when using HttpClient

I have a method that does a POST like below

var response = await client.PostAsJsonAsync(url, entity);

if (response.IsSuccessStatusCode)
{
        // read the response as strongly typed object
        return await response.Content.ReadAsAsync<T>();
}

My question is how can I obtain the actual JSON that got posted from the entity object. I would like to log the JSON that gets POSTED, so it will be nice to have that without me having to do a json serialize myself.

Upvotes: 193

Views: 218320

Answers (5)

Keith
Keith

Reputation: 155832

I use dependency injection and the built in logging to make this configurable. I use this pattern when OpenAPI or SOAP definitions are unreliable, or there are bugs in the auto client generation.

When you use an HttpClient it automatically logs headers and precise timings at the trace level for that configured name.

For instance, of you injected services.AddHttpClient("MyHttpClient" ...) you can get headers with this in your appsettings.json:

{
  "Logging": {
    "LogLevel": {
      "Default": "Information",
      ...
      "System.Net.Http.HttpClient.MyHttpClient": "Trace"
    },

I extend this to request/response content logging with this:

using Microsoft.Extensions.DependencyInjection;
using Microsoft.Extensions.Http;
using Microsoft.Extensions.Logging;
using System.Net.Http;

/// <summary>HTTP request wrapper that logs request/response body.
/// Use this for debugging issues with third party services.</summary>
class TraceContentLoggingHandler(HttpMessageHandler innerHandler, ILogger logger) : DelegatingHandler(innerHandler)
{
    protected override async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
    {
        if (logger is null || !logger.IsEnabled(LogLevel.Trace)) 
            return await base.SendAsync(request, cancellationToken); // If not tracing, skip logging
       
        if (request.Content is not null)
            logger.LogTrace("""
                Request body {URI} 
                {Content}
                """, 
                request.RequestUri,
                await request.Content.ReadAsStringAsync(cancellationToken));

        var response = await base.SendAsync(request, cancellationToken); // This is disposable, but if we dispose it the ultimate caller can't read the content

        if (response.Content is not null)
            logger.LogInformation("""
                Response {Code} {Status} 
                {Content}
                """,
                (int)response.StatusCode, 
                response.ReasonPhrase, 
                await ReadableResponse(response, cancellationToken));

        return response;
    }

    static async Task<string> ReadableResponse(HttpResponseMessage response, CancellationToken cancellationToken)
    {
        string? contentType = response.Content.Headers.GetValues("Content-Type")?.FirstOrDefault();
        if (contentType == "application/zip")
            return $"ZIP file {response.Content.Headers.GetValues("Content-Length").FirstOrDefault()} bytes";

        return await response.Content.ReadAsStringAsync(cancellationToken);
    }

}

public static class TraceContentLoggingExtension {

    /// <summary>When trace logging is enabled, log request/response bodies.
    /// However, this means that trace logging will be slower.</summary>
    public static IHttpClientBuilder AddTraceContentLogging(this IHttpClientBuilder httpClientBuilder)
    {
        // Get the logger for the named HttpClient
        var sp = httpClientBuilder.Services.BuildServiceProvider();
        var logger = sp.GetService<ILoggerFactory>()?.CreateLogger($"System.Net.Http.HttpClient.{httpClientBuilder.Name}");

        // If trace logging is enabled, add the logging handler
        if (logger?.IsEnabled(LogLevel.Trace) ?? false)
            httpClientBuilder.Services.Configure(
                httpClientBuilder.Name,
                (HttpClientFactoryOptions options) =>
                    options.HttpMessageHandlerBuilderActions.Add(b =>
                        b.PrimaryHandler = new TraceContentLoggingHandler(b.PrimaryHandler, logger)
                ));

        return httpClientBuilder;
    }
}

Then, when registering the HttpClient I can set the trace logging in the DI setup:

serviceCollection.AddHttpClient("MyHttpClient", ...). // Named HTTP client
    AddTraceContentLogging(); // Add content logging when trace

...

// Any time I get this client from DI it can log content
var httpClient = serviceProvider.GetRequiredService<IHttpClientFactory>().CreateClient("MyHttpClient");

This then makes the request/response logging something I can turn on or off with the "Trace".

This improves over the accepted answer in a few ways:

  • Turn on and off from a config file
  • Uses the built in logging (can go to EventLog or whatever) instead of Console
  • Avoids new HttpClient and the pain that causes (always use an HttpClientFactory)
  • Easy to add to any existing dependency injected HttpClient
  • Works in .NET8

However, you should still be careful with this...

  • It slows down trace logging significantly - not a problem for debugging, but for any performance testing this will slow the existing trace timings down.
  • Streaming APIs don't work with it - the logging will stall the code you want to actually handle the request
  • Both headers and content will get logged, this can very easily expose things like security keys you don't want shared. For that reason I often make this DEBUG only:
serviceCollection.AddHttpClient("MyHttpClient", client =>
{
    client.DefaultRequestHeaders.Add("Authorization", $"Basic {encodedSecret}");
})
#if DEBUG
            .AddTraceContentLogging();
#endif

Upvotes: 5

Rami A.
Rami A.

Reputation: 10602

NOTE: This works with .NET Framework ONLY!

May be working with .NET 7+ (https://github.com/dotnet/runtime/issues/23937)


See http://mikehadlow.blogspot.com/2012/07/tracing-systemnet-to-debug-http-clients.html

To configure a System.Net listener to output to both the console and a log file, add the following to your assembly configuration file:

<system.diagnostics>
  <trace autoflush="true" />
  <sources>
    <source name="System.Net">
      <listeners>
        <add name="MyTraceFile"/>
        <add name="MyConsole"/>
      </listeners>
    </source>
  </sources>
  <sharedListeners>
    <add
      name="MyTraceFile"
      type="System.Diagnostics.TextWriterTraceListener"
      initializeData="System.Net.trace.log" />
    <add name="MyConsole" type="System.Diagnostics.ConsoleTraceListener" />
  </sharedListeners>
  <switches>
    <add name="System.Net" value="Verbose" />
  </switches>
</system.diagnostics>

Upvotes: 74

StuS
StuS

Reputation: 857

Network tracing also available for next objects (see article on msdn)

  • System.Net.Sockets Some public methods of the Socket, TcpListener, TcpClient, and Dns classes
  • System.Net Some public methods of the HttpWebRequest, HttpWebResponse, FtpWebRequest, and FtpWebResponse classes, and SSL debug information (invalid certificates, missing issuers list, and client certificate errors.)
  • System.Net.HttpListener Some public methods of the HttpListener, HttpListenerRequest, and HttpListenerResponse classes.
  • System.Net.Cache Some private and internal methods in System.Net.Cache.
  • System.Net.Http Some public methods of the HttpClient, DelegatingHandler, HttpClientHandler, HttpMessageHandler, MessageProcessingHandler, and WebRequestHandler classes.
  • System.Net.WebSockets.WebSocket Some public methods of the ClientWebSocket and WebSocket classes.

Put the following lines of code to the configuration file:

<configuration>  
  <system.diagnostics>  
    <sources>  
      <source name="System.Net" tracemode="includehex" maxdatasize="1024">  
        <listeners>  
          <add name="System.Net"/>  
        </listeners>  
      </source>  
      <source name="System.Net.Cache">  
        <listeners>  
          <add name="System.Net"/>  
        </listeners>  
      </source>  
      <source name="System.Net.Http">  
        <listeners>  
          <add name="System.Net"/>  
        </listeners>  
      </source>  
      <source name="System.Net.Sockets">  
        <listeners>  
          <add name="System.Net"/>  
        </listeners>  
      </source>  
      <source name="System.Net.WebSockets">  
        <listeners>  
          <add name="System.Net"/>  
        </listeners>  
      </source>  
    </sources>  
    <switches>  
      <add name="System.Net" value="Verbose"/>  
      <add name="System.Net.Cache" value="Verbose"/>  
      <add name="System.Net.Http" value="Verbose"/>  
      <add name="System.Net.Sockets" value="Verbose"/>  
      <add name="System.Net.WebSockets" value="Verbose"/>  
    </switches>  
    <sharedListeners>  
      <add name="System.Net"  
        type="System.Diagnostics.TextWriterTraceListener"  
        initializeData="network.log"  
      />  
    </sharedListeners>  
    <trace autoflush="true"/>  
  </system.diagnostics>  
</configuration>  

Upvotes: 27

user1096164
user1096164

Reputation: 1

The easiest solution would be to use Wireshark and trace the HTTP tcp flow.

Upvotes: -35

Kiran
Kiran

Reputation: 57989

An example of how you could do this:

Some notes:

  • LoggingHandler intercepts the request before it handles it to HttpClientHandler which finally writes to the wire.

  • PostAsJsonAsync extension internally creates an ObjectContent and when ReadAsStringAsync() is called in the LoggingHandler, it causes the formatter inside ObjectContent to serialize the object and that's the reason you are seeing the content in json.

Logging handler:

public class LoggingHandler : DelegatingHandler
{
    public LoggingHandler(HttpMessageHandler innerHandler)
        : base(innerHandler)
    {
    }

    protected override async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
    {
        Console.WriteLine("Request:");
        Console.WriteLine(request.ToString());
        if (request.Content != null)
        {
            Console.WriteLine(await request.Content.ReadAsStringAsync());
        }
        Console.WriteLine();

        HttpResponseMessage response = await base.SendAsync(request, cancellationToken);

        Console.WriteLine("Response:");
        Console.WriteLine(response.ToString());
        if (response.Content != null)
        {
            Console.WriteLine(await response.Content.ReadAsStringAsync());
        }
        Console.WriteLine();

        return response;
    }
}

Chain the above LoggingHandler with HttpClient:

HttpClient client = new HttpClient(new LoggingHandler(new HttpClientHandler()));
HttpResponseMessage response = client.PostAsJsonAsync(baseAddress + "/api/values", "Hello, World!").Result;

Output:

Request:
Method: POST, RequestUri: 'http://kirandesktop:9095/api/values', Version: 1.1, Content: System.Net.Http.ObjectContent`1[
[System.String, mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089]], Headers:
{
  Content-Type: application/json; charset=utf-8
}
"Hello, World!"

Response:
StatusCode: 200, ReasonPhrase: 'OK', Version: 1.1, Content: System.Net.Http.StreamContent, Headers:
{
  Date: Fri, 20 Sep 2013 20:21:26 GMT
  Server: Microsoft-HTTPAPI/2.0
  Content-Length: 15
  Content-Type: application/json; charset=utf-8
}
"Hello, World!"

Upvotes: 332

Related Questions