Skip to content

Commit

Permalink
feat(webhook): add webhook.auditLoggingEnabled config property (#4840)
Browse files Browse the repository at this point in the history
* fix(webhook): fix format string in response-too-big error message

* feat(webhook): add webhook.auditLoggedEnabled config property

which defaults to false.  When true, log information about each webhook request and response.

* refactor(webhook): use a literal for WebhookConfiguration's logger class

to remove the trailing bits from

com.netflix.spinnaker.orca.webhook.config.WebhookConfiguration$$EnhancerBySpringCGLIB$$2337d14d

* refactor(webhook): move audit logging after validation

so we only log a message for requests we actually send/responses we actually receive.
This seems more correct, but also paves the way to including the sizes in the log
messages.  With request/response size limits it's a bounded amount of work.

* feat(webhook): include header byte count in audit logging

* refactor(webhook): introduce WebhookConfiguration.getRequestBodyContentLength

to facilitate adding request body length to the audit log

* feat(webhook): include request body content length in the audit log

* feat(webhook): include response body content length in audit log
  • Loading branch information
dbyron-sf authored Feb 17, 2025
1 parent 77cff27 commit c50f922
Show file tree
Hide file tree
Showing 3 changed files with 84 additions and 20 deletions.
1 change: 1 addition & 0 deletions orca-webhook/orca-webhook.gradle
Original file line number Diff line number Diff line change
Expand Up @@ -31,6 +31,7 @@ dependencies {
implementation("com.jayway.jsonpath:json-path")
implementation("com.squareup.okhttp3:okhttp")
implementation("com.jakewharton.retrofit:retrofit1-okhttp3-client:1.1.0")
implementation("net.logstash.logback:logstash-logback-encoder")

testImplementation("com.github.tomakehurst:wiremock-jre8-standalone")
testImplementation("com.squareup.okhttp3:mockwebserver")
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,8 @@

package com.netflix.spinnaker.orca.webhook.config;

import static net.logstash.logback.argument.StructuredArguments.kv;

import com.netflix.spinnaker.kork.crypto.TrustStores;
import com.netflix.spinnaker.kork.crypto.X509Identity;
import com.netflix.spinnaker.kork.crypto.X509IdentitySource;
Expand Down Expand Up @@ -45,6 +47,7 @@
import okhttp3.Response;
import okhttp3.ResponseBody;
import okio.BufferedSource;
import okio.Okio;
import org.apache.commons.lang3.StringUtils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
Expand Down Expand Up @@ -75,7 +78,7 @@
public class WebhookConfiguration {
private final WebhookProperties webhookProperties;

private final Logger log = LoggerFactory.getLogger(getClass());
private final Logger log = LoggerFactory.getLogger(WebhookConfiguration.class);

@Autowired
public WebhookConfiguration(WebhookProperties webhookProperties) {
Expand Down Expand Up @@ -110,12 +113,35 @@ public ClientHttpRequestFactory webhookRequestFactory(
.addNetworkInterceptor(
chain -> {
Request request = chain.request();

validateRequestSize(request, webhookProperties.getMaxRequestBytes());

if (webhookProperties.isAuditLoggingEnabled()) {
log.info(
"sending webhook request: {},{},{},{}",
kv("httpMethod", request.method()),
kv("url", request.url()),
kv("headerByteCount", request.headers().byteCount()),
kv("contentLength", getRequestBodyContentLength(request)));
}

Response response = chain.proceed(request);

validateResponseSize(response, webhookProperties.getMaxResponseBytes());

if (webhookProperties.isAuditLoggingEnabled()) {
log.info(
"received webhook response: {},{},{},{},{},{}",
kv("httpMethod", response.request().method()),
kv("url", response.request().url()),
kv("responseCode", response.code()),
kv("headerByteCount", response.headers().byteCount()),
kv("contentLength", getResponseBodyContentLength(response)),
kv(
"latencyMs",
response.receivedResponseAtMillis() - response.sentRequestAtMillis()));
}

if (response.isRedirect()) {
String redirectLocation = response.header("Location");
if (!webhookProperties.isFollowRedirects()) {
Expand Down Expand Up @@ -156,6 +182,21 @@ public ClientHttpRequestFactory webhookRequestFactory(
return requestFactory;
}

/** Return the content length of a request body, or -1 for unknown. */
private long getRequestBodyContentLength(Request request) throws IOException {
RequestBody requestBody = request.body();
if (requestBody == null) {
return 0;
}

try {
return requestBody.contentLength();
} catch (IOException e) {
log.error("exception retrieving content length of request to {}", request.url(), e);
throw e;
}
}

/** Return if the request size is valid. Throw an exception otherwise. */
private void validateRequestSize(Request request, long maxRequestBytes) throws IOException {
if (maxRequestBytes <= 0L) {
Expand All @@ -179,37 +220,56 @@ private void validateRequestSize(Request request, long maxRequestBytes) throws I
return;
}

long contentLength = 0L;
try {
contentLength = requestBody.contentLength();
if (contentLength == -1) {
// Given that OkHttp3ClientHttpRequestFactory.buildRequest (called by
// OkHttp3ClientRequest.executeInternal) has a byte array argument, this
// doesn't seem possible. Reject the request in case it ends up being
// too big. Yes, this is paranoid, but seems safer.
String message =
String.format(
"unable to verify size of body in request to %s, content length not set",
request.url());
log.error(message);
throw new IllegalStateException(message);
}
} catch (IOException e) {
log.error("exception retrieving content length of request to {}", request.url(), e);
throw e;
long contentLength = getRequestBodyContentLength(request);
if (contentLength == -1) {
// Given that OkHttp3ClientHttpRequestFactory.buildRequest (called by
// OkHttp3ClientRequest.executeInternal) has a byte array argument, this
// doesn't seem possible. Reject the request in case it ends up being
// too big. Yes, this is paranoid, but seems safer.
String message =
String.format(
"unable to verify size of body in request to %s, content length not set",
request.url());
log.error(message);
throw new IllegalStateException(message);
}

long totalSize = headerSize + contentLength;
if (totalSize > maxRequestBytes) {
String message =
String.format(
"rejecting request to %s with %s byte body, maxRequestBytes: {}",
"rejecting request to %s with %s byte body, maxRequestBytes: %s",
request.url(), totalSize, maxRequestBytes);
log.info(message);
throw new IllegalArgumentException(message);
}
}

/** Return the content length of a response body */
private long getResponseBodyContentLength(Response response) throws IOException {
ResponseBody responseBody = response.body();
if (responseBody == null) {
return 0;
}

long contentLength = responseBody.contentLength();
if (contentLength != -1) {
return contentLength;
}

// Nothing has read the body yet. This is the likely case. Peek into the body to get the
// length. See okhttp.Response.peekBody for inspiration.
//
// contentLength = responseBody.bytes().length
//
// consumes the response such that future processing fails since the underlying buffer is
// closed.
//
// Note also that responseBody.source().getBuffer().size() doesn't work reliably.
BufferedSource peeked = responseBody.source().peek();
return peeked.readAll(Okio.blackhole());
}

/** Return if the response size is valid. Throw an exception otherwise. */
private void validateResponseSize(Response response, long maxResponseBytes) throws IOException {
if (maxResponseBytes <= 0L) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -99,6 +99,9 @@ public class WebhookProperties {
*/
private long readTimeoutMs = 20000L;

/** True to enable audit logging */
private boolean auditLoggingEnabled = false;

@Data
@NoArgsConstructor
public static class TrustSettings {
Expand Down

0 comments on commit c50f922

Please sign in to comment.