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

How to enable logging? #258

Closed
Nearga opened this issue Aug 29, 2016 · 8 comments
Closed

How to enable logging? #258

Nearga opened this issue Aug 29, 2016 · 8 comments
Labels

Comments

@Nearga
Copy link

Nearga commented Aug 29, 2016

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.

@ahmedalejo
Copy link

ahmedalejo commented Aug 29, 2016

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

@Nearga
Copy link
Author

Nearga commented Aug 29, 2016

Aha, thanks, i'll check it

@ahmedalejo
Copy link

ahmedalejo commented Aug 30, 2016

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==========

@Nearga
Copy link
Author

Nearga commented Aug 30, 2016

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);

@ahmedalejo
Copy link

ahmedalejo commented Aug 31, 2016

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 notifications@github.com 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
#258 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/AGr-6sQ8fjSsmzVexeWBnm1YDA0NzTd9ks5qlKRIgaJpZM4Jv9Fu
.

@dbacinski
Copy link

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

@ahmedalejo
Copy link

ahmedalejo commented Apr 1, 2017

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

@vullnetyy
Copy link

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.

@lock lock bot added the outdated label Jun 24, 2019
@lock lock bot locked and limited conversation to collaborators Jun 24, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests

5 participants