Add a LoggingEventListener and use it in okcurl

[amirlivneh]

A basic logger, as discussed in #4315.

To install a LoggingEventListener that uses the platform logger:

builder.eventListenerFactory(new LoggingEventListener.Factory());

The user can also pass a custom Logger:

Logger logger = new Logger() {
  @Override
  public void log(String message) {
    ...
  }
};
builder.eventListenerFactory(new LoggingEventListener.Factory(logger));

Sample output:

$ okcurl -v "https://httpbin.org/redirect-to?status_code=307&url=https://api.twitter.com/robots.txt"

[t=0] callStart: Request{method=GET, url=https://httpbin.org/redirect-to?status_code=307&url=https://api.twitter.com/robots.txt, tags={}}
[t=13] dnsStart: httpbin.org
[t=233] dnsEnd: [httpbin.org/54.174.228.92, httpbin.org/52.4.75.11, httpbin.org/54.173.32.212, httpbin.org/54.152.208.69, httpbin.org/54.172.170.160, httpbin.org/54.165.51.142, httpbin.org/54.209.64.71, httpbin.org/54.164.206.44]
[t=247] connectStart: httpbin.org/54.174.228.92:443 DIRECT
[t=310] secureConnectStart
[t=605] secureConnectEnd
[t=605] connectEnd: http/1.1
[t=606] connectionAcquired: Connection{httpbin.org:443, proxy=DIRECT hostAddress=httpbin.org/54.174.228.92:443 cipherSuite=TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 protocol=http/1.1}
[t=607] requestHeadersStart
[t=608] requestHeadersEnd
[t=610] responseHeadersStart
[t=670] responseHeadersEnd: Response{protocol=http/1.1, code=307, message=TEMPORARY REDIRECT, url=https://httpbin.org/redirect-to?status_code=307&url=https://api.twitter.com/robots.txt}
[t=670] responseBodyStart
[t=676] responseBodyEnd: byteCount=0
[t=677] connectionReleased
[t=677] callEnd
[t=677] dnsStart: api.twitter.com
[t=830] dnsEnd: [api.twitter.com/104.244.42.66, api.twitter.com/104.244.42.2, api.twitter.com/104.244.42.130, api.twitter.com/104.244.42.194]
[t=831] connectStart: api.twitter.com/104.244.42.66:443 DIRECT
[t=858] secureConnectStart
[t=993] secureConnectEnd
[t=993] connectEnd: http/1.1
[t=994] connectionAcquired: Connection{api.twitter.com:443, proxy=DIRECT hostAddress=api.twitter.com/104.244.42.66:443 cipherSuite=TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 protocol=http/1.1}
[t=994] requestHeadersStart
[t=994] requestHeadersEnd
[t=994] responseHeadersStart
[t=1029] responseHeadersEnd: Response{protocol=http/1.1, code=200, message=OK, url=https://api.twitter.com/robots.txt}
[t=1029] responseBodyStart
[t=1031] responseBodyEnd: byteCount=138
[t=1031] connectionReleased
[t=1031] callEnd
# Used for Google app indexing. See https://developers.google.com/app-indexing/webmasters/server
User-agent: Googlebot
Disallow:

User-agent: *
Disallow: /

[yschimke]

Should we try to bridge HttpLoggingInterceptor.Logger somehow? Seems strange to have two. Presumably over time there will be a complete set of each.

Maybe even introduce as a public API? It seems like something we should encourage e.g. someone implementing a Interceptor should log via Platform.log, but as that is internal API, a way to achieve that correctly would be nice.

[amirlivneh]

You're right. It does introduce duplication. I thought it would be confusing to pass a HttpLoggingInterceptor.Logger to the LoggingEventListener.Factory constructor. I can make this change if you think it's better.

If by a public API you mean making Logger a top-level class, I can do that. To avoid a breaking API change, we then may need to keep HttpLoggingInterceptor(HttpLoggingInterceptor.Logger) as a deprecated constructor in addition to a new HttpLoggingInterceptor(Logger) constructor.

Let me know what you feel would be best here.

[yschimke]

I suggest sitting for a day in case there are more voices

[swankjesse]

Since this is in the same package as the HttpLoggingInterceptor, think it’s kosher to just use HttpLoggingInterceptor.Logger directly. Fewer types is better.

[yschimke]

This looks like a fantastic first version to me.

cc @swankjesse @JakeWharton @dave-r12

[swankjesse]

Agreed, this is fantastic. If you can combine the two loggers into one, I’d love to merge this and ship it in our next release.

Sorry for the slow response.

[swankjesse]

Since this is in the same package as the HttpLoggingInterceptor, think it’s kosher to just use HttpLoggingInterceptor.Logger directly. Fewer types is better.

[amirlivneh]

@swankjesse, should we add a top-level Logger class to streamline LoggingEventListener's API and deprecate HttpLoggingInterceptor.Logger?

[swankjesse]

Nope. Let's keep the current API. The cost of migrating this is high and the benefit is low.

[swankjesse]

😍

[amirlivneh]

@yschimke, @swankjesse, will you be receptive to a PR that adds logging of request/response headers and a PR that adds Handshake.toString() and use it in secureConnectEnd()?

[swankjesse]

I think headers logging is probably too much for this thing. This is for observing timing; the logging interceptor is for debugging content.

[yschimke]

@swankjesse I think content vs timing and connections. So handshake seems useful here. But I agree about not including variable output like headers, request/response body.