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.

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

Add ExceptionReportingServerErrorHandler to log unhandled exceptions #4687

Merged
merged 35 commits into from Mar 27, 2023

Conversation

seonWKim
Copy link
Contributor

@seonWKim seonWKim commented Feb 21, 2023

Motivation:

If LoggingService is not added to services, exceptions(without appropriate exception handlers) thrown by those services are not caught. This default behavior can be confusing for users because, even though exceptions are being thrown, there are no logs to indicate that anything is wrong.
The purpose of this feature is to enable the reporting of unhandled exceptions by default, so that users can be alerted to any issues and take appropriate action.

Modifications:

  • com.linecorp.armeria.defaultUnhandledExceptionsReportIntervalMillis vm option can be used to configure intervals between reporting unhandled exceptions in milliseconds.
  • Add shouldReportUnhandledExceptions to DefaultServiceRequestContext which determines whether to log unhandled exceptions.
  • Add ExceptionReportingServerErrorHandler to report unhandled exceptions.

Result:

  • Closes #<4324>. (If this resolves the issue.)
  • User will be able to check the number of uncaught exceptions and thrown exception periodically by default.
  • If multiple servers with same MeterRegistry exist, armeria.server.exceptions.unhandled metrics will be the sum of all the number of unhandled exceptions on those servers. However, individual servers will be reported with logs that include total number of unhandled exceptions specific to that server only.

Example

  • User can change default settings by using ServerBuilder
final ServerBuilder sb = Server.builder();
sb.http(port);
sb.unhandledExceptionsReportIntervalMillis(1000L);
configureServices(sb);
return sb.build();
  • Result
[armeria-common-worker-nio-2-1] WARN com.linecorp.armeria.server.ExceptionReportingServerErrorHandler - Observed 1 unhandled exceptions in last 1000ms(1000000000ns). Please consider adding the LoggingService decorator to get detailed error logs. One of the thrown exceptions:
example.armeria.server.annotated.ExceptionHandlerService$LocallySpecificException
	at example.armeria.server.annotated.ExceptionHandlerService.exception1(ExceptionHandlerService.java:36)
	at com.linecorp.armeria.internal.server.annotation.AnnotatedService.invoke(AnnotatedService.java:355)
	at com.linecorp.armeria.internal.server.annotation.AnnotatedService.lambda$serve0$8(AnnotatedService.java:324)
	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:684)
...

Closes #4324

@seonWKim seonWKim marked this pull request as ready for review February 21, 2023 01:37
Copy link
Member

@trustin trustin left a comment

Choose a reason for hiding this comment

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

Looks like we're going into the right direction. Just minor comments only!

- use `exceptionReportingInterval` instead of `shouldLogUncaughtExceptions` and `logUncaughtExceptionsIntervalInSeconds`
- remove `needsToWarn`
- rename `UncaughtExceptionsServerErrorHandler` to `ExceptionReportingServerErrorHandler`
- Add tests
@seonWKim
Copy link
Contributor Author

@trustin Thank you for the review, I've applied the comments. 🙇‍♂️

@seonWKim
Copy link
Contributor Author

seonWKim commented Feb 23, 2023

I'm considering whether it's worthwhile to unify the terms log and report, since some methods and variables use log while others use report. For instance, there is method called logExceptions and some variables called shouldLogException, and there's a class named ExceptionReportingServerErrorHandler that's used for reporting exceptions.

@trustin
Copy link
Member

trustin commented Feb 23, 2023

I'm considering whether it's worthwhile to unify the terms log and report, since some methods and variables use log while others use report. For instance, there is method called logExceptions and some variables called shouldLogException, and there's a class named ExceptionReportingServerErrorHandler that's used for reporting exceptions.

That's a good point, @seonwoo960000. How about this:

  • Rename {ServerBuilder,ServerConfig}.exceptionReportingInterval() to unloggedExceptionReportInterval()
  • Rename ServiceRequestContext.shouldLogException to shouldReportUnloggedException

seonWKim and others added 3 commits February 23, 2023 23:25
…ingServerErrorHandler.java

Co-authored-by: Trustin Lee <t@motd.kr>
…ingServerErrorHandler.java

Co-authored-by: Trustin Lee <t@motd.kr>
@seonWKim
Copy link
Contributor Author

seonWKim commented Feb 24, 2023

I'm considering whether it's worthwhile to unify the terms log and report, since some methods and variables use log while others use report. For instance, there is method called logExceptions and some variables called shouldLogException, and there's a class named ExceptionReportingServerErrorHandler that's used for reporting exceptions.

That's a good point, @seonwoo960000. How about this:

  • Rename {ServerBuilder,ServerConfig}.exceptionReportingInterval() to unloggedExceptionReportInterval()
  • Rename ServiceRequestContext.shouldLogException to shouldReportUnloggedException

Sure ~ I'll apply your comments. I'll also change some methods or javadocs that contain the word log to report if it's more appropriate.

Btw, I'll apply the renaming as follow. It's just about capital letters fix.

  • unloggedExceptionReportInterval -> unLoggedExceptionReportInterval
  • shouldReportUnloggedException -> shouldReportUnLoggedException

- unLog -> unlog
- stop all running servers in tests
- use assert instead of throwing exceptions(on which arguments have already been checked)
Copy link
Member

@trustin trustin left a comment

Choose a reason for hiding this comment

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

I think we're getting close to completion now. Great! There's one ask left - Could you add Flags.defaultUnloggedExceptionReportIntervalMillis() and use it as a default value in ServerBuilder, so that a user can override the default without touching code?

@trustin
Copy link
Member

trustin commented Feb 24, 2023

Test failure - https://github.com/line/armeria/actions/runs/4260354188/jobs/7413433723#step:7:1541 Seems trivial to fix 😉

@seonWKim
Copy link
Contributor Author

seonWKim commented Mar 8, 2023

@trustin I've fixed as below:

  • Add MicrometerCounter which counts the total number of unhandled exceptions on a single MeterRegistry. ExceptionReportingServerErrorHandler uses MicrometerUtil to register MicrometerCounter to MeterRegistry

@ikhoon
Copy link
Contributor

ikhoon commented Mar 9, 2023

@seonwoo960000 Could you resolve the conflicts?

- `MicrometerCounter` is added which can be shared across multiple servers with same `MeterRegistry`
- Singleton is removed from `ExceptionReportingServerErrorHandler`
@seonWKim
Copy link
Contributor Author

seonWKim commented Mar 9, 2023

@seonwoo960000 Could you resolve the conflicts?

Sure, I've resolved the conflict.

- change `log` position
- use `Counter` for meterRegistry
Copy link
Member

@trustin trustin left a comment

Choose a reason for hiding this comment

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

Thanks for putting your effort on this, @seonwoo960000. LGTM 👍 🙇

Copy link
Contributor

@ikhoon ikhoon left a comment

Choose a reason for hiding this comment

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

Thanks, @seonwoo960000! 🎉 🎉

Copy link
Contributor

@jrhee17 jrhee17 left a comment

Choose a reason for hiding this comment

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

Looks really nice! Thanks @seonwoo960000 🙇 👍 🚀

Copy link
Member

@minwoox minwoox left a comment

Choose a reason for hiding this comment

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

Thanks a lot for your hard work!

@@ -1961,6 +1987,14 @@ private DefaultServerConfig buildServerConfig(List<ServerPort> serverPorts) {
errorHandler = errorHandler.orElse(ServerErrorHandler.ofDefault());
}

if (unhandledExceptionsReportInterval != Duration.ZERO) {
final ExceptionReportingServerErrorHandler reportingErrorHandler =
new ExceptionReportingServerErrorHandler(meterRegistry, this.errorHandler,
Copy link
Member

Choose a reason for hiding this comment

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

This would remove the ServerErrorHandler.ofDefault(). 😄

Suggested change
new ExceptionReportingServerErrorHandler(meterRegistry, this.errorHandler,
new ExceptionReportingServerErrorHandler(meterRegistry, errorHandler,

Copy link
Member

Choose a reason for hiding this comment

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

I found a but that existed after fixing this. 😉
ad948d0

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Thank you for your detailed review!

@minwoox minwoox merged commit 5f6a3b4 into line:main Mar 27, 2023
8 of 10 checks passed
@minwoox
Copy link
Member

minwoox commented Mar 27, 2023

Great job, @seonwoo960000! 🎉 🎉 🎉
Let's get to the next issue. 😆

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

No uncaught service exceptions are logged out of the box.
5 participants