Add more logs for http requests (#58)
* Add more logs in http requests * Switch log level to debug
This commit is contained in:
Pavel Popov
GitHub
parent
a9376627b1
commit
86438e9615
2
pom.xml
2
pom.xml
@ -4,7 +4,7 @@
|
||||
<modelVersion>4.0.0</modelVersion>
|
||||
|
||||
<artifactId>hooker</artifactId>
|
||||
<version>2.0.13-SNAPSHOT</version>
|
||||
<version>2.0.14-SNAPSHOT</version>
|
||||
<packaging>jar</packaging>
|
||||
|
||||
<name>hooker</name>
|
||||
|
||||
@ -0,0 +1,276 @@
|
||||
package com.rbkmoney.hooker.logging;
|
||||
|
||||
import okhttp3.*;
|
||||
import okhttp3.internal.http.HttpHeaders;
|
||||
import okio.Buffer;
|
||||
import okio.BufferedSource;
|
||||
import org.slf4j.LoggerFactory;
|
||||
|
||||
import java.io.EOFException;
|
||||
import java.io.IOException;
|
||||
import java.nio.charset.Charset;
|
||||
import java.util.concurrent.TimeUnit;
|
||||
|
||||
/**
|
||||
* An OkHttp interceptor which logs request and response information. Can be applied as an
|
||||
* {@linkplain OkHttpClient#interceptors() application interceptor} or as a {@linkplain
|
||||
* OkHttpClient#networkInterceptors() network interceptor}. <p> The format of the logs created by
|
||||
* this class should not be considered stable and may change slightly between releases. If you need
|
||||
* a stable logging format, use your own interceptor.
|
||||
*/
|
||||
public final class HttpLoggingInterceptor implements Interceptor {
|
||||
private static final Charset UTF8 = Charset.forName("UTF-8");
|
||||
private static final org.slf4j.Logger log = LoggerFactory.getLogger(HttpLoggingInterceptor.class);
|
||||
|
||||
public enum Level {
|
||||
/**
|
||||
* No logs.
|
||||
*/
|
||||
NONE,
|
||||
/**
|
||||
* Logs request and response lines.
|
||||
* <p>
|
||||
* <p>Example:
|
||||
* <pre>{@code
|
||||
* --> POST /greeting http/1.1 (3-byte body)
|
||||
*
|
||||
* <-- 200 OK (22ms, 6-byte body)
|
||||
* }</pre>
|
||||
*/
|
||||
BASIC,
|
||||
/**
|
||||
* Logs request and response lines and their respective headers.
|
||||
* <p>
|
||||
* <p>Example:
|
||||
* <pre>{@code
|
||||
* --> POST /greeting http/1.1
|
||||
* Host: example.com
|
||||
* Content-Type: plain/text
|
||||
* Content-Length: 3
|
||||
* --> END POST
|
||||
*
|
||||
* <-- 200 OK (22ms)
|
||||
* Content-Type: plain/text
|
||||
* Content-Length: 6
|
||||
* <-- END HTTP
|
||||
* }</pre>
|
||||
*/
|
||||
HEADERS,
|
||||
/**
|
||||
* Logs request and response lines and their respective headers and bodies (if present).
|
||||
* <p>
|
||||
* <p>Example:
|
||||
* <pre>{@code
|
||||
* --> POST /greeting http/1.1
|
||||
* Host: example.com
|
||||
* Content-Type: plain/text
|
||||
* Content-Length: 3
|
||||
*
|
||||
* Hi?
|
||||
* --> END POST
|
||||
*
|
||||
* <-- 200 OK (22ms)
|
||||
* Content-Type: plain/text
|
||||
* Content-Length: 6
|
||||
*
|
||||
* Hello!
|
||||
* <-- END HTTP
|
||||
* }</pre>
|
||||
*/
|
||||
BODY
|
||||
}
|
||||
|
||||
public interface Logger {
|
||||
void log(String message);
|
||||
|
||||
/**
|
||||
* A {@link Logger} defaults output appropriate for the current platform.
|
||||
*/
|
||||
Logger DEFAULT = message -> log.debug(message);
|
||||
}
|
||||
|
||||
public HttpLoggingInterceptor() {
|
||||
this(Logger.DEFAULT);
|
||||
}
|
||||
|
||||
public HttpLoggingInterceptor(Logger logger) {
|
||||
this.logger = logger;
|
||||
}
|
||||
|
||||
private final Logger logger;
|
||||
|
||||
private volatile Level level = Level.BODY;
|
||||
|
||||
/**
|
||||
* Change the level at which this interceptor logs.
|
||||
*/
|
||||
public HttpLoggingInterceptor setLevel(Level level) {
|
||||
if (level == null) throw new NullPointerException("level == null. Use Level.NONE instead.");
|
||||
this.level = level;
|
||||
return this;
|
||||
}
|
||||
|
||||
public Level getLevel() {
|
||||
return level;
|
||||
}
|
||||
|
||||
@Override
|
||||
public Response intercept(Chain chain) throws IOException {
|
||||
Level level = this.level;
|
||||
|
||||
Request request = chain.request();
|
||||
if (level == Level.NONE) {
|
||||
return chain.proceed(request);
|
||||
}
|
||||
|
||||
boolean logBody = level == Level.BODY;
|
||||
boolean logHeaders = logBody || level == Level.HEADERS;
|
||||
|
||||
RequestBody requestBody = request.body();
|
||||
boolean hasRequestBody = requestBody != null;
|
||||
|
||||
Connection connection = chain.connection();
|
||||
StringBuilder message = new StringBuilder("--> \n")
|
||||
.append(request.method())
|
||||
.append(' ').append(request.url())
|
||||
.append(connection != null ? " " + connection.protocol() : "").append('\n');
|
||||
if (!logHeaders && hasRequestBody) {
|
||||
message.append(" (").append(requestBody.contentLength()).append("-byte body)").append('\n');
|
||||
}
|
||||
//logger.log(requestStartMessage);
|
||||
|
||||
if (logHeaders) {
|
||||
if (hasRequestBody) {
|
||||
// Request body headers are only present when installed as a network interceptor. Force
|
||||
// them to be included (when available) so there values are known.
|
||||
if (requestBody.contentType() != null) {
|
||||
message.append("Content-Type: ").append(requestBody.contentType()).append('\n');
|
||||
}
|
||||
if (requestBody.contentLength() != -1) {
|
||||
message.append("Content-Length: ").append(requestBody.contentLength()).append('\n');
|
||||
}
|
||||
}
|
||||
|
||||
Headers headers = request.headers();
|
||||
for (int i = 0, count = headers.size(); i < count; i++) {
|
||||
String name = headers.name(i);
|
||||
// Skip headers from the request body as they are explicitly logged above.
|
||||
if (!"Authorization".equalsIgnoreCase(name)) {
|
||||
message.append(name).append(": ").append(headers.value(i)).append('\n');
|
||||
}
|
||||
}
|
||||
|
||||
if (!logBody || !hasRequestBody) {
|
||||
message.append("\n--> END ").append(request.method());
|
||||
} else if (bodyEncoded(request.headers())) {
|
||||
message.append("\n--> END ").append(request.method()).append(" (encoded body omitted)");
|
||||
} else {
|
||||
message.append('\n');
|
||||
Buffer buffer = new Buffer();
|
||||
requestBody.writeTo(buffer);
|
||||
|
||||
Charset charset = UTF8;
|
||||
MediaType contentType = requestBody.contentType();
|
||||
if (contentType != null) {
|
||||
charset = contentType.charset(UTF8);
|
||||
}
|
||||
|
||||
if (isPlaintext(buffer)) {
|
||||
message.append(buffer.readString(charset));
|
||||
message.append("\n--> END ").append(request.method())
|
||||
.append(" (").append(requestBody.contentLength()).append("-byte body)");
|
||||
} else {
|
||||
message.append("\n--> END ").append(request.method()).append(" (binary ")
|
||||
.append(requestBody.contentLength()).append("-byte body omitted)");
|
||||
}
|
||||
}
|
||||
}
|
||||
logger.log(message.toString());
|
||||
long startNs = System.nanoTime();
|
||||
Response response;
|
||||
try {
|
||||
response = chain.proceed(request);
|
||||
} catch (Exception e) {
|
||||
logger.log("<-- HTTP FAILED: " + e);
|
||||
throw e;
|
||||
}
|
||||
long tookMs = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startNs);
|
||||
|
||||
ResponseBody responseBody = response.body();
|
||||
long contentLength = responseBody.contentLength();
|
||||
message = new StringBuilder();
|
||||
String bodySize = contentLength != -1 ? contentLength + "-byte" : "unknown-length";
|
||||
message.append("<-- \n")
|
||||
.append(response.code())
|
||||
.append(response.message().isEmpty() ? "" : " " + response.message())
|
||||
.append(' ').append(response.request().url())
|
||||
.append(" (").append(tookMs).append("ms").append((!logHeaders ? ", " + bodySize + " body" : "") + ')').append('\n');
|
||||
|
||||
if (logHeaders) {
|
||||
Headers headers = response.headers();
|
||||
for (int i = 0, count = headers.size(); i < count; i++) {
|
||||
message.append(headers.name(i)).append(": ").append(headers.value(i)).append('\n');
|
||||
}
|
||||
|
||||
if (!logBody || !HttpHeaders.hasBody(response)) {
|
||||
message.append("\n<-- END HTTP");
|
||||
} else if (bodyEncoded(response.headers())) {
|
||||
message.append("\n<-- END HTTP (encoded body omitted)");
|
||||
} else {
|
||||
message.append('\n');
|
||||
BufferedSource source = responseBody.source();
|
||||
source.request(Long.MAX_VALUE); // Buffer the entire body.
|
||||
Buffer buffer = source.buffer();
|
||||
|
||||
Charset charset = UTF8;
|
||||
MediaType contentType = responseBody.contentType();
|
||||
if (contentType != null) {
|
||||
charset = contentType.charset(UTF8);
|
||||
}
|
||||
|
||||
if (!isPlaintext(buffer)) {
|
||||
message.append("\n<-- END HTTP (binary ").append(buffer.size()).append("-byte body omitted)");
|
||||
return response;
|
||||
}
|
||||
|
||||
if (contentLength != 0) {
|
||||
message.append(buffer.clone().readString(charset));
|
||||
}
|
||||
|
||||
logger.log(message.append("\n<-- END HTTP (").append(buffer.size()).append("-byte body)").toString());
|
||||
}
|
||||
}
|
||||
|
||||
return response;
|
||||
}
|
||||
|
||||
/**
|
||||
* Returns true if the body in question probably contains human readable text. Uses a small sample
|
||||
* of code points to detect unicode control characters commonly used in binary file signatures.
|
||||
*/
|
||||
static boolean isPlaintext(Buffer buffer) {
|
||||
try {
|
||||
Buffer prefix = new Buffer();
|
||||
long byteCount = buffer.size() < 64 ? buffer.size() : 64;
|
||||
buffer.copyTo(prefix, 0, byteCount);
|
||||
for (int i = 0; i < 16; i++) {
|
||||
if (prefix.exhausted()) {
|
||||
break;
|
||||
}
|
||||
int codePoint = prefix.readUtf8CodePoint();
|
||||
if (Character.isISOControl(codePoint) && !Character.isWhitespace(codePoint)) {
|
||||
return false;
|
||||
}
|
||||
}
|
||||
return true;
|
||||
} catch (EOFException e) {
|
||||
return false; // Truncated UTF-8 sequence.
|
||||
}
|
||||
}
|
||||
|
||||
private boolean bodyEncoded(Headers headers) {
|
||||
String contentEncoding = headers.get("Content-Encoding");
|
||||
return contentEncoding != null && !contentEncoding.equalsIgnoreCase("identity");
|
||||
}
|
||||
}
|
||||
|
||||
@ -1,5 +1,6 @@
|
||||
package com.rbkmoney.hooker.service;
|
||||
|
||||
import com.rbkmoney.hooker.logging.HttpLoggingInterceptor;
|
||||
import okhttp3.*;
|
||||
import org.slf4j.Logger;
|
||||
import org.slf4j.LoggerFactory;
|
||||
@ -17,7 +18,11 @@ public class PostSender {
|
||||
public static final String SIGNATURE_HEADER = "Content-Signature";
|
||||
|
||||
public PostSender(@Value("${merchant.callback.timeout}") int timeout) {
|
||||
HttpLoggingInterceptor httpLoggingInterceptor = new HttpLoggingInterceptor();
|
||||
httpLoggingInterceptor.setLevel(HttpLoggingInterceptor.Level.BODY);
|
||||
|
||||
this.httpClient = new OkHttpClient.Builder()
|
||||
.addInterceptor(httpLoggingInterceptor)
|
||||
.connectTimeout(timeout, TimeUnit.SECONDS)
|
||||
.writeTimeout(timeout, TimeUnit.SECONDS)
|
||||
.readTimeout(timeout, TimeUnit.SECONDS)
|
||||
|
||||
Loading…
Reference in New Issue
Block a user