Skip to content

Commit

Permalink
Fix where access log is not written when the method of a reques… (lin…
Browse files Browse the repository at this point in the history
…e#2159)

…t is not allowed

Motivation:
There's some cases that we don't call `RequestLogBuilder.endRequest()`.
- When the method of the request is not allowed
- When there's no services that match the path of the request
- and so on

Because the `RequestLog` in never complete, `AccessLogWriter` is not called so we should fix it.

Modifications:
- Call `RequestLogBuilder.endRequest()` even when `service.serve()` is not invoked
- Do not log HttpStatusException as requestCause

Result:
- You can now see the access logs when the method of a request is not allowed and there are no services that match the path.
  • Loading branch information
minwoox authored and unknown committed Oct 15, 2019
1 parent bd326e3 commit 265ed97
Show file tree
Hide file tree
Showing 2 changed files with 120 additions and 15 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -330,8 +330,9 @@ private void handleRequest(ChannelHandlerContext ctx, DecodedHttpRequest req) th
try {
routed = host.findServiceConfig(routingCtx);
} catch (HttpStatusException cause) {
// We do not need to handle HttpResponseException here because we do not use it internally.
respond(ctx, host.accessLogWriter(), req, pathAndQuery, cause.httpStatus(), null, cause);
// There's no chance that an HttpResponseException is raised so we just handle HttpStatusException.
// Just pass the null as the cause because we don't want to log HttpStatusException as the cause.
respond(ctx, host.accessLogWriter(), req, pathAndQuery, cause.httpStatus(), null, null);
return;
} catch (Throwable cause) {
logger.warn("{} Unexpected exception: {}", ctx.channel(), req, cause);
Expand Down Expand Up @@ -374,19 +375,18 @@ protocol, routingCtx, routingResult, req, getSSLSession(channel),
} catch (HttpResponseException cause) {
serviceResponse = cause.httpResponse();
} catch (Throwable cause) {
try {
final HttpStatus status;
if (cause instanceof HttpStatusException) {
status = ((HttpStatusException) cause).httpStatus();
} else {
logger.warn("{} Unexpected exception: {}, {}", reqCtx, service, req, cause);
status = HttpStatus.INTERNAL_SERVER_ERROR;
}
respond(ctx, reqCtx, reqCtx.accessLogWriter(), status, null, cause);
} finally {
logBuilder.endRequest(cause);
logBuilder.endResponse(cause);
final HttpStatus status;
final Throwable newCause;
if (cause instanceof HttpStatusException) {
status = ((HttpStatusException) cause).httpStatus();
// We don't want to log HttpStatusException and HttpResponseException as the cause.
newCause = null;
} else {
logger.warn("{} Unexpected exception: {}, {}", reqCtx, service, req, cause);
status = HttpStatus.INTERNAL_SERVER_ERROR;
newCause = cause;
}
respond(ctx, reqCtx, reqCtx.accessLogWriter(), status, null, newCause);
return;
}
final HttpResponse res = serviceResponse;
Expand Down Expand Up @@ -568,9 +568,14 @@ private ChannelFuture respond0(
final DecodedHttpRequest req = (DecodedHttpRequest) reqCtx.request();
assert req != null;
req.close();
final RequestLogBuilder logBuilder = reqCtx.logBuilder();
if (cause == null) {
logBuilder.endRequest();
} else {
logBuilder.endRequest(cause);
}

final boolean hasContent = resContent != null;
final RequestLogBuilder logBuilder = reqCtx.logBuilder();

logBuilder.startResponse();
assert responseEncoder != null;
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,100 @@
/*
* Copyright 2019 LINE Corporation
*
* LINE Corporation licenses this file to you under the Apache License,
* version 2.0 (the "License"); you may not use this file except in compliance
* with the License. You may obtain a copy of the License at:
*
* https://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
* WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
* License for the specific language governing permissions and limitations
* under the License.
*/

package com.linecorp.armeria.server;

import static org.assertj.core.api.Assertions.assertThat;
import static org.awaitility.Awaitility.await;

import java.util.concurrent.atomic.AtomicReference;

import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.RegisterExtension;

import com.linecorp.armeria.client.HttpClient;
import com.linecorp.armeria.common.AggregatedHttpResponse;
import com.linecorp.armeria.common.HttpResponse;
import com.linecorp.armeria.common.HttpStatus;
import com.linecorp.armeria.common.logging.RequestLog;
import com.linecorp.armeria.testing.junit.server.ServerExtension;

class HttpServerHandlerTest {

private static final AtomicReference<RequestLog> logHolder = new AtomicReference<>();

@RegisterExtension
static final ServerExtension server = new ServerExtension() {
@Override
protected void configure(ServerBuilder sb) throws Exception {
sb.accessLogWriter(logHolder::set, true);
sb.route()
.get("/hello")
.build((ctx, req) -> HttpResponse.of(200));
sb.route()
.get("/httpStatusException")
.build((ctx, req) -> {
throw HttpStatusException.of(201);
});
sb.route()
.get("/httpResponseException")
.build((ctx, req) -> {
throw HttpResponseException.of(201);
});
}
};

@BeforeEach
void clearLog() {
logHolder.set(null);
}

@Test
void methodNotAllowed() {
final HttpClient client = HttpClient.of(server.uri("/"));
final AggregatedHttpResponse res = client.delete("/hello").aggregate().join();
assertThat(res.status()).isSameAs(HttpStatus.METHOD_NOT_ALLOWED);
await().untilAsserted(() -> assertThat(logHolder.get().path()).isEqualTo("/hello"));
assertThat(logHolder.get().requestCause()).isNull();
}

@Test
void handleNonExistentMapping() {
final HttpClient client = HttpClient.of(server.uri("/"));
final AggregatedHttpResponse res = client.get("/non_existent").aggregate().join();
assertThat(res.status()).isSameAs(HttpStatus.NOT_FOUND);
await().untilAsserted(() -> assertThat(logHolder.get().path()).isEqualTo("/non_existent"));
assertThat(logHolder.get().requestCause()).isNull();
}

@Test
void httpStatusExceptionIsNotLoggedAsRequestCause() {
final HttpClient client = HttpClient.of(server.uri("/"));
final AggregatedHttpResponse res = client.get("/httpStatusException").aggregate().join();
assertThat(res.status()).isSameAs(HttpStatus.CREATED);
await().untilAsserted(() -> assertThat(logHolder.get().path()).isEqualTo("/httpStatusException"));
assertThat(logHolder.get().requestCause()).isNull();
}

@Test
void httpResponseExceptionIsNotLoggedAsRequestCause() {
final HttpClient client = HttpClient.of(server.uri("/"));
final AggregatedHttpResponse res = client.get("/httpResponseException").aggregate().join();
assertThat(res.status()).isSameAs(HttpStatus.CREATED);
await().untilAsserted(() -> assertThat(logHolder.get().path()).isEqualTo("/httpResponseException"));
assertThat(logHolder.get().requestCause()).isNull();
}
}

0 comments on commit 265ed97

Please sign in to comment.