Refit: How to enable logging?

Created on 30 Aug 2016  Â·  8Comments  Â·  Source: reactiveui/refit

It would be great to be able to see what is sent and what is received. Get requests works fine for me, however Posts are throwing 505 or 404 exceptions - taking a pick behind the curtains would help a lot.

outdated

Most helpful comment

var httpClient = new HttpClient(new HttpLoggingHandler()){ BaseAddress = /**/};
var contract = Refit.RestService.For<IGitApiContract>(httpClient);

HttpLoggingHandlers definition follows

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Net.Http;
using System.Net.Http.Headers;
using System.Threading;
using System.Threading.Tasks;

namespace Service.Shared.Clients
{
    public class HttpLoggingHandler : DelegatingHandler
    {
        public HttpLoggingHandler(HttpMessageHandler innerHandler = null)
            : base(innerHandler ?? new HttpClientHandler())
        { }
        async protected override Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
        {
            var req = request;
            var id = Guid.NewGuid().ToString();
            var msg = $"[{id} -   Request]";

            Debug.WriteLine($"{msg}========Start==========");
            Debug.WriteLine($"{msg} {req.Method} {req.RequestUri.PathAndQuery} {req.RequestUri.Scheme}/{req.Version}");
            Debug.WriteLine($"{msg} Host: {req.RequestUri.Scheme}://{req.RequestUri.Host}");

            foreach (var header in req.Headers)
                Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

            if (req.Content != null)
            {
                foreach (var header in req.Content.Headers)
                    Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

                if (req.Content is StringContent || this.IsTextBasedContentType(req.Headers) || this.IsTextBasedContentType(req.Content.Headers))
                {   
                    var result = await req.Content.ReadAsStringAsync();

                    Debug.WriteLine($"{msg} Content:");
                    Debug.WriteLine($"{msg} {string.Join("", result.Cast<char>().Take(255))}...");

                }
            }

            var start = DateTime.Now;

            var response = await base.SendAsync(request, cancellationToken).ConfigureAwait(false);

            var end = DateTime.Now;

            Debug.WriteLine($"{msg} Duration: {end - start}");
            Debug.WriteLine($"{msg}==========End==========");

            msg = $"[{id} - Response]";
            Debug.WriteLine($"{msg}=========Start=========");

            var resp = response;

            Debug.WriteLine($"{msg} {req.RequestUri.Scheme.ToUpper()}/{resp.Version} {(int)resp.StatusCode} {resp.ReasonPhrase}");

            foreach (var header in resp.Headers)
                Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

            if (resp.Content != null)
            {
                foreach (var header in resp.Content.Headers)
                    Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

                if (resp.Content is StringContent || this.IsTextBasedContentType(resp.Headers) || this.IsTextBasedContentType(resp.Content.Headers))
                {
                    start = DateTime.Now;
                    var result = await resp.Content.ReadAsStringAsync();
                    end = DateTime.Now;

                    Debug.WriteLine($"{msg} Content:");
                    Debug.WriteLine($"{msg} {string.Join("", result.Cast<char>().Take(255))}...");
                    Debug.WriteLine($"{msg} Duration: {end - start}");
                }
            }

            Debug.WriteLine($"{msg}==========End==========");
            return response;
        }

        readonly string[] types = new[] { "html", "text", "xml", "json", "txt", "x-www-form-urlencoded" };

        bool IsTextBasedContentType(HttpHeaders headers)
        {
            IEnumerable<string> values;
            if (!headers.TryGetValues("Content-Type", out values))
                return false;
            var header = string.Join(" ", values).ToLowerInvariant();

            return types.Any(t => header.Contains(t));
        }
    }
}

Gets Log as following:

[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request]=========Start=========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request]========Start==========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request] GET / https/1.1
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request] Host: https://www.google.com
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request] Duration: 00:00:00.2298277
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request]==========End==========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response]=========Start=========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] HTTPS/1.1 200 OK
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] X-XSS-Protection: 1; mode=block
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] X-Frame-Options: SAMEORIGIN
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Alternate-Protocol: 443:quic
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Alt-Svc: quic=":443"; ma=2592000; v="35,34,33,32,31,30"
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Vary: Accept-Encoding
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Transfer-Encoding: chunked
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Accept-Ranges: none
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Cache-Control: max-age=0, private
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Date: Tue, 30 Aug 2016 10:02:32 GMT
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] P3P: CP="This is not a P3P policy! See https://www.google.com/support/accounts/answer/151657?hl=en for more info."
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Set-Cookie: NID=85=SAxtO23sG2Xuap7whetoj9Hn353S-wRFCEifyNFeFBIRWkd5fL4h2ws3rgyvk_dfIPbX_5SYqELFHWj4nXO62FxWpC3eeurykZEZQtI-EO9KsQDWpju9SaQ3XY9xwUa7; expires=Wed, 01-Mar-2017 10:02:32 GMT; path=/; domain=.google.com.br; HttpOnly
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Server: gws
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Content-Type: text/html; charset=ISO-8859-1
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Expires: -1
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Content:
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] <!doctype html><html itemscope="" itemtype="http://schema.org/WebPage" lang="pt"><head><meta content="text/html; charset=UTF-8" http-equiv="Content-Type"><meta content="/images/branding/googleg/1x/googleg_standard_color_128dp.png" itemprop="image"><title>...
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Duration: 00:00:00.0503445
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response]==========End==========

All 8 comments

you should use a System.Net.Http.DelegatingHandler for this, will elaborate more soon

Aha, thanks, i'll check it

var httpClient = new HttpClient(new HttpLoggingHandler()){ BaseAddress = /**/};
var contract = Refit.RestService.For<IGitApiContract>(httpClient);

HttpLoggingHandlers definition follows

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Net.Http;
using System.Net.Http.Headers;
using System.Threading;
using System.Threading.Tasks;

namespace Service.Shared.Clients
{
    public class HttpLoggingHandler : DelegatingHandler
    {
        public HttpLoggingHandler(HttpMessageHandler innerHandler = null)
            : base(innerHandler ?? new HttpClientHandler())
        { }
        async protected override Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
        {
            var req = request;
            var id = Guid.NewGuid().ToString();
            var msg = $"[{id} -   Request]";

            Debug.WriteLine($"{msg}========Start==========");
            Debug.WriteLine($"{msg} {req.Method} {req.RequestUri.PathAndQuery} {req.RequestUri.Scheme}/{req.Version}");
            Debug.WriteLine($"{msg} Host: {req.RequestUri.Scheme}://{req.RequestUri.Host}");

            foreach (var header in req.Headers)
                Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

            if (req.Content != null)
            {
                foreach (var header in req.Content.Headers)
                    Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

                if (req.Content is StringContent || this.IsTextBasedContentType(req.Headers) || this.IsTextBasedContentType(req.Content.Headers))
                {   
                    var result = await req.Content.ReadAsStringAsync();

                    Debug.WriteLine($"{msg} Content:");
                    Debug.WriteLine($"{msg} {string.Join("", result.Cast<char>().Take(255))}...");

                }
            }

            var start = DateTime.Now;

            var response = await base.SendAsync(request, cancellationToken).ConfigureAwait(false);

            var end = DateTime.Now;

            Debug.WriteLine($"{msg} Duration: {end - start}");
            Debug.WriteLine($"{msg}==========End==========");

            msg = $"[{id} - Response]";
            Debug.WriteLine($"{msg}=========Start=========");

            var resp = response;

            Debug.WriteLine($"{msg} {req.RequestUri.Scheme.ToUpper()}/{resp.Version} {(int)resp.StatusCode} {resp.ReasonPhrase}");

            foreach (var header in resp.Headers)
                Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

            if (resp.Content != null)
            {
                foreach (var header in resp.Content.Headers)
                    Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

                if (resp.Content is StringContent || this.IsTextBasedContentType(resp.Headers) || this.IsTextBasedContentType(resp.Content.Headers))
                {
                    start = DateTime.Now;
                    var result = await resp.Content.ReadAsStringAsync();
                    end = DateTime.Now;

                    Debug.WriteLine($"{msg} Content:");
                    Debug.WriteLine($"{msg} {string.Join("", result.Cast<char>().Take(255))}...");
                    Debug.WriteLine($"{msg} Duration: {end - start}");
                }
            }

            Debug.WriteLine($"{msg}==========End==========");
            return response;
        }

        readonly string[] types = new[] { "html", "text", "xml", "json", "txt", "x-www-form-urlencoded" };

        bool IsTextBasedContentType(HttpHeaders headers)
        {
            IEnumerable<string> values;
            if (!headers.TryGetValues("Content-Type", out values))
                return false;
            var header = string.Join(" ", values).ToLowerInvariant();

            return types.Any(t => header.Contains(t));
        }
    }
}

Gets Log as following:

[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request]=========Start=========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request]========Start==========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request] GET / https/1.1
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request] Host: https://www.google.com
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request] Duration: 00:00:00.2298277
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request]==========End==========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response]=========Start=========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] HTTPS/1.1 200 OK
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] X-XSS-Protection: 1; mode=block
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] X-Frame-Options: SAMEORIGIN
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Alternate-Protocol: 443:quic
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Alt-Svc: quic=":443"; ma=2592000; v="35,34,33,32,31,30"
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Vary: Accept-Encoding
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Transfer-Encoding: chunked
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Accept-Ranges: none
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Cache-Control: max-age=0, private
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Date: Tue, 30 Aug 2016 10:02:32 GMT
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] P3P: CP="This is not a P3P policy! See https://www.google.com/support/accounts/answer/151657?hl=en for more info."
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Set-Cookie: NID=85=SAxtO23sG2Xuap7whetoj9Hn353S-wRFCEifyNFeFBIRWkd5fL4h2ws3rgyvk_dfIPbX_5SYqELFHWj4nXO62FxWpC3eeurykZEZQtI-EO9KsQDWpju9SaQ3XY9xwUa7; expires=Wed, 01-Mar-2017 10:02:32 GMT; path=/; domain=.google.com.br; HttpOnly
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Server: gws
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Content-Type: text/html; charset=ISO-8859-1
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Expires: -1
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Content:
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] <!doctype html><html itemscope="" itemtype="http://schema.org/WebPage" lang="pt"><head><meta content="text/html; charset=UTF-8" http-equiv="Content-Type"><meta content="/images/branding/googleg/1x/googleg_standard_color_128dp.png" itemprop="image"><title>...
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Duration: 00:00:00.0503445
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response]==========End==========

Works like a charmed!

Can i use it in pair with NativeMessageHandler?

Also, Resharper recommends to change
async protected override Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
to
protected override async Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)

and
await Task.Delay(1).ConfigureAwait(false);
to
await Task.Delay(1, cancellationToken).ConfigureAwait(false);

Ofcourse you can, but i recommend using this handler only when debugging(#if DEBUG).
But you can use it with Analytics/Telemetry framework to track Request-Response delay

and Oh, Who am i to disagree with R#? lol

On Tue, 30 Aug 2016 at 18:44 Nearga [email protected] wrote:

Works like a charmed!

Can i use it in pair with NativeMessageHandler?

Also, Resharper recommends to change
async protected override Task SendAsync(HttpRequestMessage request,
CancellationToken cancellationToken)
to
protected override async Task SendAsync(HttpRequestMessage request,
CancellationToken cancellationToken)

and
await Task.Delay(1).ConfigureAwait(false);
to
await Task.Delay(1, cancellationToken).ConfigureAwait(false);

—
You are receiving this because you commented.

Reply to this email directly, view it on GitHub
https://github.com/paulcbetts/refit/issues/258#issuecomment-243591306,
or mute the thread
https://github.com/notifications/unsubscribe-auth/AGr-6sQ8fjSsmzVexeWBnm1YDA0NzTd9ks5qlKRIgaJpZM4Jv9Fu
.

Added support for x-www-form-urlencoded bodies
https://gist.github.com/dbacinski/5bd2793e33b0377ecfbcd980d6841f1e

Thanks @dbacinski i updated my comment to include "x-www-form-urlencoded"

var httpClient = new HttpClient(new HttpLoggingHandler()){ BaseAddress = /**/};
var contract = Refit.RestService.For<IGitApiContract>(httpClient);

HttpLoggingHandlers definition follows

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq;
using System.Net.Http;
using System.Net.Http.Headers;
using System.Threading;
using System.Threading.Tasks;

namespace Service.Shared.Clients
{
    public class HttpLoggingHandler : DelegatingHandler
    {
        public HttpLoggingHandler(HttpMessageHandler innerHandler = null)
            : base(innerHandler ?? new HttpClientHandler())
        { }
        async protected override Task<HttpResponseMessage> SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
        {
            var req = request;
            var id = Guid.NewGuid().ToString();
            var msg = $"[{id} -   Request]";

            Debug.WriteLine($"{msg}========Start==========");
            Debug.WriteLine($"{msg} {req.Method} {req.RequestUri.PathAndQuery} {req.RequestUri.Scheme}/{req.Version}");
            Debug.WriteLine($"{msg} Host: {req.RequestUri.Scheme}://{req.RequestUri.Host}");

            foreach (var header in req.Headers)
                Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

            if (req.Content != null)
            {
                foreach (var header in req.Content.Headers)
                    Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

                if (req.Content is StringContent || this.IsTextBasedContentType(req.Headers) || this.IsTextBasedContentType(req.Content.Headers))
                {   
                    var result = await req.Content.ReadAsStringAsync();

                    Debug.WriteLine($"{msg} Content:");
                    Debug.WriteLine($"{msg} {string.Join("", result.Cast<char>().Take(255))}...");

                }
            }

            var start = DateTime.Now;

            var response = await base.SendAsync(request, cancellationToken).ConfigureAwait(false);

            var end = DateTime.Now;

            Debug.WriteLine($"{msg} Duration: {end - start}");
            Debug.WriteLine($"{msg}==========End==========");

            msg = $"[{id} - Response]";
            Debug.WriteLine($"{msg}=========Start=========");

            var resp = response;

            Debug.WriteLine($"{msg} {req.RequestUri.Scheme.ToUpper()}/{resp.Version} {(int)resp.StatusCode} {resp.ReasonPhrase}");

            foreach (var header in resp.Headers)
                Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

            if (resp.Content != null)
            {
                foreach (var header in resp.Content.Headers)
                    Debug.WriteLine($"{msg} {header.Key}: {string.Join(", ", header.Value)}");

                if (resp.Content is StringContent || this.IsTextBasedContentType(resp.Headers) || this.IsTextBasedContentType(resp.Content.Headers))
                {
                    start = DateTime.Now;
                    var result = await resp.Content.ReadAsStringAsync();
                    end = DateTime.Now;

                    Debug.WriteLine($"{msg} Content:");
                    Debug.WriteLine($"{msg} {string.Join("", result.Cast<char>().Take(255))}...");
                    Debug.WriteLine($"{msg} Duration: {end - start}");
                }
            }

            Debug.WriteLine($"{msg}==========End==========");
            return response;
        }

        readonly string[] types = new[] { "html", "text", "xml", "json", "txt", "x-www-form-urlencoded" };

        bool IsTextBasedContentType(HttpHeaders headers)
        {
            IEnumerable<string> values;
            if (!headers.TryGetValues("Content-Type", out values))
                return false;
            var header = string.Join(" ", values).ToLowerInvariant();

            return types.Any(t => header.Contains(t));
        }
    }
}

Gets Log as following:

[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request]=========Start=========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request]========Start==========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request] GET / https/1.1
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request] Host: https://www.google.com
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request] Duration: 00:00:00.2298277
[83544d2e-6f8b-4e6c-9827-a5e58557f99c -  Request]==========End==========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response]=========Start=========
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] HTTPS/1.1 200 OK
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] X-XSS-Protection: 1; mode=block
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] X-Frame-Options: SAMEORIGIN
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Alternate-Protocol: 443:quic
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Alt-Svc: quic=":443"; ma=2592000; v="35,34,33,32,31,30"
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Vary: Accept-Encoding
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Transfer-Encoding: chunked
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Accept-Ranges: none
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Cache-Control: max-age=0, private
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Date: Tue, 30 Aug 2016 10:02:32 GMT
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] P3P: CP="This is not a P3P policy! See https://www.google.com/support/accounts/answer/151657?hl=en for more info."
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Set-Cookie: NID=85=SAxtO23sG2Xuap7whetoj9Hn353S-wRFCEifyNFeFBIRWkd5fL4h2ws3rgyvk_dfIPbX_5SYqELFHWj4nXO62FxWpC3eeurykZEZQtI-EO9KsQDWpju9SaQ3XY9xwUa7; expires=Wed, 01-Mar-2017 10:02:32 GMT; path=/; domain=.google.com.br; HttpOnly
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Server: gws
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Content-Type: text/html; charset=ISO-8859-1
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Expires: -1
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Content:
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] <!doctype html><html itemscope="" itemtype="http://schema.org/WebPage" lang="pt"><head><meta content="text/html; charset=UTF-8" http-equiv="Content-Type"><meta content="/images/branding/googleg/1x/googleg_standard_color_128dp.png" itemprop="image"><title>...
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response] Duration: 00:00:00.0503445
[83544d2e-6f8b-4e6c-9827-a5e58557f99c - Response]==========End==========

It would be nice if we could make this like a little optional helper to the library.

Was this page helpful?
0 / 5 - 0 ratings