Skip to content

Commit a8220b5

Browse files
seonWKimseonWKim
authored
Fix ExceptionReportingServiceErrorHandler to ignore expected exceptions. (#4922)
Motivation: Do not log ignorable exceptions. Modifications: - Fix `ExceptionReportingServiceErrorHandler` to ignore ignorable exceptions. - Modify `DefaultUnhandledExceptionReporter` log messages. - Remove `ExceptionReportingServiceErrorHandlerTest`and add `DefaultUnhandledExceptionReporterTest` which test `DefaultUnhandledExceptionReporter` Result: - Closes #4861 . - When ignorable exceptions are thrown, `DefaultUnhandledExceptionReporter` will not report anything.
1 parent 427e800 commit a8220b5

File tree

5 files changed

+180
-106
lines changed

5 files changed

+180
-106
lines changed

‎core/src/main/java/com/linecorp/armeria/server/DefaultUnhandledExceptionsReporter.java

Lines changed: 6 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -101,15 +101,16 @@ private void reportException() {
101101

102102
final Throwable exception = thrownException;
103103
if (exception != null) {
104-
logger.warn("Observed {} unhandled exceptions in last {}. " +
105-
"Please consider adding the LoggingService decorator to get detailed error logs. " +
106-
"One of the thrown exceptions:",
104+
logger.warn("Observed {} exception(s) that didn't reach a LoggingService in the last {}. " +
105+
"Please consider adding a LoggingService as the outermost decorator to get " +
106+
"detailed error logs. One of the thrown exceptions:",
107107
newExceptionsCount,
108108
TextFormatter.elapsed(intervalMillis, TimeUnit.MILLISECONDS), exception);
109109
thrownException = null;
110110
} else {
111-
logger.warn("Observed {} unhandled exceptions in last {}. " +
112-
"Please consider adding the LoggingService decorator to get detailed error logs.",
111+
logger.warn("Observed {} exception(s) that didn't reach a LoggingService in the last {}. " +
112+
"Please consider adding a LoggingService as the outermost decorator to get " +
113+
"detailed error logs.",
113114
newExceptionsCount, TextFormatter.elapsed(intervalMillis, TimeUnit.MILLISECONDS));
114115
}
115116

‎core/src/main/java/com/linecorp/armeria/server/ExceptionReportingServiceErrorHandler.java

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,7 @@
2121
import com.linecorp.armeria.common.HttpStatus;
2222
import com.linecorp.armeria.common.RequestHeaders;
2323
import com.linecorp.armeria.common.annotation.Nullable;
24+
import com.linecorp.armeria.common.util.Exceptions;
2425

2526
final class ExceptionReportingServiceErrorHandler implements ServiceErrorHandler {
2627

@@ -42,6 +43,9 @@ public HttpResponse onServiceException(ServiceRequestContext ctx, Throwable caus
4243
}
4344

4445
private static boolean isIgnorableException(Throwable cause) {
46+
if (Exceptions.isExpected(cause)) {
47+
return true;
48+
}
4549
return (cause instanceof HttpStatusException || cause instanceof HttpResponseException) &&
4650
cause.getCause() == null;
4751
}

‎core/src/test/java/com/linecorp/armeria/server/AnnotatedServiceBindingBuilderTest.java

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -149,7 +149,7 @@ void testAllConfigurationsAreRespected() {
149149
final ServiceRequestContext sctx = ServiceRequestContext.builder(HttpRequest.of(HttpMethod.GET, "/"))
150150
.build();
151151
// serviceErrorHandler is composed with ServerErrorHandler so we cannot do the equality check.
152-
assertThat(homeFoo.errorHandler().onServiceException(sctx, null)
152+
assertThat(homeFoo.errorHandler().onServiceException(sctx, new IllegalArgumentException("cause"))
153153
.aggregate()
154154
.join()
155155
.status()).isSameAs(HttpStatus.OK);
@@ -162,7 +162,7 @@ void testAllConfigurationsAreRespected() {
162162
assertThat(homeBar.verboseResponses()).isTrue();
163163
assertThat(homeBar.multipartUploadsLocation()).isSameAs(multipartUploadsLocation);
164164
// serviceErrorHandler is composed with ServerErrorHandler so we cannot do the equality check.
165-
assertThat(homeBar.errorHandler().onServiceException(sctx, null)
165+
assertThat(homeBar.errorHandler().onServiceException(sctx, new IllegalArgumentException("cause"))
166166
.aggregate()
167167
.join()
168168
.status()).isSameAs(HttpStatus.OK);

‎core/src/test/java/com/linecorp/armeria/server/DefaultUnhandledExceptionReporterTest.java

Lines changed: 127 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,127 @@
1+
/*
2+
* Copyright 2023 LINE Corporation
3+
*
4+
* LINE Corporation licenses this file to you under the Apache License,
5+
* version 2.0 (the "License"); you may not use this file except in compliance
6+
* with the License. You may obtain a copy of the License at:
7+
*
8+
* https://www.apache.org/licenses/LICENSE-2.0
9+
*
10+
* Unless required by applicable law or agreed to in writing, software
11+
* distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
12+
* WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
13+
* License for the specific language governing permissions and limitations
14+
* under the License.
15+
*/
16+
17+
package com.linecorp.armeria.server;
18+
19+
import static org.assertj.core.api.Assertions.assertThat;
20+
import static org.awaitility.Awaitility.await;
21+
22+
import java.time.Duration;
23+
24+
import org.junit.jupiter.api.AfterEach;
25+
import org.junit.jupiter.api.BeforeEach;
26+
import org.junit.jupiter.api.Test;
27+
import org.junit.jupiter.api.extension.RegisterExtension;
28+
import org.mockito.Spy;
29+
import org.slf4j.LoggerFactory;
30+
31+
import com.linecorp.armeria.common.HttpStatus;
32+
import com.linecorp.armeria.server.logging.LoggingService;
33+
import com.linecorp.armeria.testing.junit5.server.ServerExtension;
34+
35+
import ch.qos.logback.classic.Logger;
36+
import ch.qos.logback.classic.spi.ILoggingEvent;
37+
import ch.qos.logback.core.read.ListAppender;
38+
39+
class DefaultUnhandledExceptionReporterTest {
40+
41+
@Spy
42+
final ListAppender<ILoggingEvent> logAppender = new ListAppender<>();
43+
final Logger errorHandlerLogger =
44+
(Logger) LoggerFactory.getLogger(DefaultUnhandledExceptionsReporter.class);
45+
private static final long reportIntervalMillis = 1000;
46+
private static final long awaitIntervalMillis = 2000;
47+
private static volatile boolean throwNonIgnorableException;
48+
49+
@BeforeEach
50+
public void attachAppender() {
51+
logAppender.start();
52+
errorHandlerLogger.addAppender(logAppender);
53+
throwNonIgnorableException = false;
54+
}
55+
56+
@AfterEach
57+
public void detachAppender() {
58+
errorHandlerLogger.detachAppender(logAppender);
59+
logAppender.list.clear();
60+
}
61+
62+
@RegisterExtension
63+
static ServerExtension server = new ServerExtension() {
64+
@Override
65+
protected void configure(ServerBuilder sb) {
66+
sb.route()
67+
.get("/logging-service-subsequently-decorated")
68+
.decorator(service -> (ctx, req) -> {
69+
if (throwNonIgnorableException) {
70+
throw new IllegalArgumentException("Non-ignorable exception");
71+
}
72+
return service.serve(ctx, req);
73+
})
74+
.decorator(LoggingService.newDecorator())
75+
.build((ctx, req) -> {
76+
throw HttpStatusException.of(HttpStatus.BAD_REQUEST);
77+
});
78+
sb.route()
79+
.get("/logging-service-previously-decorated")
80+
.decorator(LoggingService.newDecorator())
81+
.decorator(service -> (ctx, req) -> {
82+
if (throwNonIgnorableException) {
83+
throw new IllegalArgumentException("Non-ignorable exception");
84+
}
85+
return service.serve(ctx, req);
86+
})
87+
.build((ctx, req) -> {
88+
throw HttpStatusException.of(HttpStatus.BAD_REQUEST);
89+
});
90+
sb.unhandledExceptionsReportInterval(Duration.ofMillis(reportIntervalMillis));
91+
}
92+
};
93+
94+
@Test
95+
void allExceptionShouldNotBeReportedWhenLoggingServiceIsSubsequentlyDecorated() throws Exception {
96+
assertThat(server.blockingWebClient().get("/logging-service-subsequently-decorated").status().code())
97+
.isEqualTo(400);
98+
throwNonIgnorableException = true;
99+
assertThat(server.blockingWebClient().get("/logging-service-subsequently-decorated").status().code())
100+
.isEqualTo(500);
101+
Thread.sleep(reportIntervalMillis + awaitIntervalMillis);
102+
assertThat(logAppender.list).isEmpty();
103+
}
104+
105+
@Test
106+
void nonIgnorableExceptionShouldBeReportedWhenLoggingServiceIsPreviouslyDecorated() {
107+
throwNonIgnorableException = true;
108+
assertThat(server.blockingWebClient().get("/logging-service-previously-decorated").status().code())
109+
.isEqualTo(500);
110+
await().atMost(Duration.ofMillis(reportIntervalMillis + awaitIntervalMillis))
111+
.untilAsserted(() -> assertThat(logAppender.list).isNotEmpty());
112+
113+
assertThat(logAppender.list
114+
.stream()
115+
.filter(event -> event.getFormattedMessage().contains(
116+
"Observed 1 exception(s) that didn't reach a LoggingService"))
117+
.findAny()).isNotEmpty();
118+
}
119+
120+
@Test
121+
void ignorableExceptionShouldNotBeReportedEvenThoughLoggingServiceIsPreviouslyDecorated() throws Exception {
122+
assertThat(server.blockingWebClient().get("/logging-service-previously-decorated").status().code())
123+
.isEqualTo(400);
124+
Thread.sleep(reportIntervalMillis + awaitIntervalMillis);
125+
assertThat(logAppender.list).isEmpty();
126+
}
127+
}

‎core/src/test/java/com/linecorp/armeria/server/ExceptionReportingServiceErrorHandlerTest.java

Lines changed: 41 additions & 99 deletions
Original file line numberDiff line numberDiff line change
@@ -16,127 +16,69 @@
1616

1717
package com.linecorp.armeria.server;
1818

19-
import static org.assertj.core.api.Assertions.assertThat;
20-
import static org.awaitility.Awaitility.await;
19+
import static org.mockito.ArgumentMatchers.any;
20+
import static org.mockito.Mockito.reset;
21+
import static org.mockito.Mockito.times;
22+
import static org.mockito.Mockito.verify;
23+
import static org.mockito.Mockito.when;
2124

22-
import java.time.Duration;
25+
import java.nio.channels.ClosedChannelException;
2326

24-
import org.junit.jupiter.api.AfterEach;
2527
import org.junit.jupiter.api.BeforeEach;
2628
import org.junit.jupiter.api.Test;
27-
import org.mockito.Spy;
28-
import org.slf4j.LoggerFactory;
29-
30-
import com.linecorp.armeria.client.BlockingWebClient;
31-
import com.linecorp.armeria.common.HttpResponse;
32-
import com.linecorp.armeria.common.HttpStatus;
33-
import com.linecorp.armeria.server.logging.LoggingService;
34-
35-
import ch.qos.logback.classic.Logger;
36-
import ch.qos.logback.classic.spi.ILoggingEvent;
37-
import ch.qos.logback.core.read.ListAppender;
29+
import org.mockito.Mock;
3830

3931
class ExceptionReportingServiceErrorHandlerTest {
4032

41-
@Spy
42-
final ListAppender<ILoggingEvent> logAppender = new ListAppender<>();
43-
final Logger errorHandlerLogger =
44-
(Logger) LoggerFactory.getLogger(DefaultUnhandledExceptionsReporter.class);
45-
private static final long reportIntervalMillis = 1000;
46-
private static final long awaitIntervalMillis = 2000;
33+
@Mock
34+
private ServiceErrorHandler delegate;
35+
@Mock
36+
private UnhandledExceptionsReporter reporter;
37+
@Mock
38+
private ServiceRequestContext ctx;
39+
40+
private ExceptionReportingServiceErrorHandler serviceErrorHandler;
4741

4842
@BeforeEach
49-
public void attachAppender() {
50-
logAppender.start();
51-
errorHandlerLogger.addAppender(logAppender);
43+
void setUp() {
44+
reset(reporter);
45+
reset(ctx);
46+
serviceErrorHandler = new ExceptionReportingServiceErrorHandler(delegate, reporter);
5247
}
5348

54-
@AfterEach
55-
public void detachAppender() {
56-
errorHandlerLogger.detachAppender(logAppender);
57-
logAppender.list.clear();
49+
@Test
50+
void onServiceExceptionShouldNotReportWhenShouldReportUnhandledExceptionsIsFalse() {
51+
when(ctx.shouldReportUnhandledExceptions()).thenReturn(false);
52+
serviceErrorHandler.onServiceException(ctx, new IllegalArgumentException("Test"));
53+
verify(reporter, times(0)).report(any());
5854
}
5955

6056
@Test
61-
void httpStatusExceptionWithCauseLogged() throws Exception {
62-
final Server server = Server.builder()
63-
.service("/hello", (ctx, req) -> {
64-
throw HttpStatusException.of(HttpStatus.BAD_REQUEST,
65-
new IllegalArgumentException("test"));
66-
})
67-
.unhandledExceptionsReportInterval(Duration.ofMillis(reportIntervalMillis))
68-
.build();
69-
try {
70-
server.start().join();
71-
BlockingWebClient.of("http://127.0.0.1:" + server.activeLocalPort()).get("/hello");
72-
await().atMost(Duration.ofMillis(reportIntervalMillis + awaitIntervalMillis))
73-
.untilAsserted(() -> assertThat(logAppender.list).isNotEmpty());
74-
75-
assertThat(logAppender.list
76-
.stream()
77-
.filter(event -> event.getFormattedMessage().contains(
78-
"Observed 1 unhandled exceptions"))
79-
.findAny()
80-
).isNotEmpty();
81-
} finally {
82-
server.stop();
83-
}
57+
void onServiceExceptionShouldNotReportWhenCauseIsExpected() {
58+
when(ctx.shouldReportUnhandledExceptions()).thenReturn(true);
59+
serviceErrorHandler.onServiceException(ctx, new ClosedChannelException());
60+
verify(reporter, times(0)).report(any());
8461
}
8562

8663
@Test
87-
void httpStatusExceptionWithoutCauseIsIgnored() throws Exception {
88-
final Server server = Server.builder()
89-
.service("/hello", (ctx, req) -> {
90-
throw HttpStatusException.of(HttpStatus.BAD_REQUEST);
91-
})
92-
.unhandledExceptionsReportInterval(Duration.ofMillis(reportIntervalMillis))
93-
.build();
94-
try {
95-
server.start().join();
96-
BlockingWebClient.of("http://127.0.0.1:" + server.activeLocalPort()).get("/hello");
97-
Thread.sleep(reportIntervalMillis + awaitIntervalMillis);
98-
99-
assertThat(logAppender.list).isEmpty();
100-
} finally {
101-
server.stop();
102-
}
64+
void onServiceExceptionShouldReportWhenCauseIsNotExpected() {
65+
when(ctx.shouldReportUnhandledExceptions()).thenReturn(true);
66+
serviceErrorHandler.onServiceException(ctx, new IllegalArgumentException("Test"));
67+
verify(reporter, times(1)).report(any());
10368
}
10469

10570
@Test
106-
void exceptionShouldNotBeLoggedWhenDecoratedWithLoggingService() throws Exception {
107-
final Server server = Server.builder()
108-
.service("/hello", (ctx, req) -> {
109-
throw new IllegalArgumentException("test");
110-
})
111-
.unhandledExceptionsReportInterval(Duration.ofMillis(reportIntervalMillis))
112-
.decorator(LoggingService.newDecorator())
113-
.build();
114-
115-
try {
116-
server.start().join();
117-
BlockingWebClient.of("http://127.0.0.1:" + server.activeLocalPort()).get("/hello");
118-
Thread.sleep(reportIntervalMillis + awaitIntervalMillis);
119-
120-
assertThat(logAppender.list).isEmpty();
121-
} finally {
122-
server.stop();
123-
}
71+
void onServiceExceptionShouldNotReportWhenCauseIsHttpStatusExceptionAndCauseNull() {
72+
when(ctx.shouldReportUnhandledExceptions()).thenReturn(true);
73+
serviceErrorHandler.onServiceException(ctx, HttpStatusException.of(500));
74+
verify(reporter, times(0)).report(any());
12475
}
12576

12677
@Test
127-
void exceptionShouldNotBeLoggedWhenNoExceptionIsThrown() throws Exception {
128-
final Server server = Server.builder()
129-
.service("/hello", (ctx, req) -> HttpResponse.of(HttpStatus.OK))
130-
.decorator(LoggingService.newDecorator())
131-
.build();
132-
try {
133-
server.start().join();
134-
BlockingWebClient.of("http://127.0.0.1:" + server.activeLocalPort()).get("/hello");
135-
Thread.sleep(reportIntervalMillis + awaitIntervalMillis);
136-
137-
assertThat(logAppender.list).isEmpty();
138-
} finally {
139-
server.stop();
140-
}
78+
void onServiceExceptionShouldReportWhenCauseIsHttpStatusExceptionAndCauseNonNull() {
79+
when(ctx.shouldReportUnhandledExceptions()).thenReturn(true);
80+
serviceErrorHandler.onServiceException(
81+
ctx, HttpStatusException.of(500, new IllegalArgumentException("test")));
82+
verify(reporter, times(1)).report(any());
14183
}
14284
}

0 commit comments

Comments
 (0)