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.

Sign up for GitHub

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

Reduce cost of logging in REST Client #27074

Merged
merged 1 commit into from
Aug 3, 2022
Merged

Reduce cost of logging in REST Client #27074

Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
39 changes: 31 additions & 8 deletions ...runtime/src/main/java/org/jboss/resteasy/reactive/client/logging/DefaultClientLogger.java
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,10 +1,11 @@
package org.jboss.resteasy.reactive.client.logging;

import io.vertx.core.Handler;
import io.vertx.core.MultiMap;
import io.vertx.core.buffer.Buffer;
import io.vertx.core.http.HttpClientRequest;
import io.vertx.core.http.HttpClientResponse;
import java.util.stream.Collectors;
import java.util.Map;
import org.jboss.logging.Logger;
import org.jboss.resteasy.reactive.client.api.ClientLogger;

Expand All @@ -20,14 +21,25 @@ public void setBodySize(int bodySize) {

@Override
public void logResponse(HttpClientResponse response, boolean redirect) {
response.bodyHandler(body -> log.debugf("%s: %s %s, Status[%d %s], Headers[%s], Body:\n%s",
redirect ? "Redirect" : "Response",
response.request().getMethod(), response.request().absoluteURI(), response.statusCode(),
response.statusMessage(), asString(response.headers()), bodyToString(body)));
if (!log.isDebugEnabled()) {
return;
}
response.bodyHandler(new Handler<>() {
@Override
public void handle(Buffer body) {
log.debugf("%s: %s %s, Status[%d %s], Headers[%s], Body:\n%s",
redirect ? "Redirect" : "Response",
response.request().getMethod(), response.request().absoluteURI(), response.statusCode(),
response.statusMessage(), asString(response.headers()), bodyToString(body));
}
});
}

@Override
public void logRequest(HttpClientRequest request, Buffer body, boolean omitBody) {
if (!log.isDebugEnabled()) {
return;
}
if (omitBody) {
log.debugf("Request: %s %s Headers[%s], Body omitted",
request.getMethod(), request.absoluteURI(), asString(request.headers()));
Expand All @@ -50,8 +62,19 @@ private String bodyToString(Buffer body) {
}

private String asString(MultiMap headers) {
return headers.entries().stream()
.map(e -> String.format("%s=%s", e.getKey(), e.getValue()))
.collect(Collectors.joining(" "));
if (headers.isEmpty()) {
return "";
}
StringBuilder sb = new StringBuilder((headers.size() * (6 + 1 + 6)) + (headers.size() - 1)); // this is a very rough estimate of a result like 'key1=value1 key2=value2'
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I fail to see why we should make this more complicated if only used for debug logging? I can understand doing things like that in a hot path but here?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Complicated how? It's just iterating over the headers and building up a String. How is that more complicated than was was being done with lambdas?

Copy link
Contributor

@jorsol jorsol Aug 2, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

14 lines vs 3 lines, pre-calculating the header size, iterating the entries, checking if the entry is the first, and so on... yes this has added complexity.

Sure, the streams, lambda, and String.format approach will be slower, but it's more readable, and if it's already guarded by isDebugEnabled() and is not in a hot path, then this might not add value in the final execution.

Having said that I appreciate that Quarkus tries to squeeze every ms of performance, but it might be better to focus on more critical paths.

Copy link
Contributor Author

@geoand geoand Aug 2, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

14 lines vs 3 lines, pre-calculating the header size, iterating the entries, checking if the entry is the first, and so on... yes this has added complexity.

I wouldn't say so, because it's code that anyone that knows even the slightest Java can write without any effort.

As for the header size pre-calculation, I honestly don't see why people are tripping over it - it's just a heuristic that easily could have been left out, but its application results in less allocations.

Copy link
Contributor Author

@geoand geoand Aug 2, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Having said that I appreciate that Quarkus tries to squash every ms of performance, but it might be better to focus on more critical paths

I truly appreciate the input, but the squezing of performance out of Quarkus is an ongoing task. In this specific case I just happen to come across something that was not performant (this is important as I did not go hunting for performance issues and come up with this...) and I addressed it - it literally took 5 minutes, it's not like it took time from other tasks...

It's always good to keep in mind the context of how development works in a large project when attempting to apply generalized (but otherwise well intended) statements.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I truly appreciate the input, but the squezing of performance out of Quarkus is an ongoing task. In this specific case I just happen to come across something that was not performant (this is important as I did not go hunting for performance issues and come up with this...) and I addressed it - it literally took 5 minutes, it's not like it took time from other tasks...

It's always good to keep in mind the context of how development works in a large project when attempting to apply generalized (but otherwise well intended) statements.

Thank you, I know this is a different kind of project and I didn't want to apply generalized statements, I was following the same observation of Guillaume, I can read the code perfectly (and probably everyone involved in the project can), but claiming that anyone that knows even the slightest Java can write without any effort, well, it's just not realistic.

Anyway, since the context of the project is different, it's perfectly fine. 👍🏽

boolean isFirst = true;
for (Map.Entry<String, String> entry : headers) {
if (isFirst) {
isFirst = false;
} else {
sb.append(' ');
}
sb.append(entry.getKey()).append('=').append(entry.getValue());
}
return sb.toString();
}
}