이번 포스팅에서는 LINE의 대표적인 오픈소스인 Armeria에 기여한 경험을 공유하고자 합니다.
Armeria
Armeria는 Java, Kotlin 또는 Scala로 작성된 오픈 소스 비동기 HTTP 및 gRPC 클라이언트 및 서버 프레임워크입니다. Armeria는 java 진영의 대표적인 비동기 서버 프레임워크인 Netty를 기반으로 하며 netty를 더 쉽게 사용할 수 있는 API를 제공합니다. Netty를 기반으로 요청을 비동기적으로 처리하므로 확장성이 크다는 장점이 있습니다.
Contribute
Armeria는 annotated service를 통해서 요청을 처리할 수 있습니다.
@Get("/hello")
public String hello() {
return "hello"
}하지만 annotated service의 요청을 처리하는 과정에서 exception이 발생하는 경우 해당 exception을 로깅하기 위해서는 별도로 LoggingService를 등록해야 합니다. 만약 별도로 LoggingService를 등록하지 않으면 exception을 확인할 수 없습니다. 여기서 LoggingDecorator은 LoggingService를 decorator의 형태로 편리하게 등록할 수 있는 armeria의 기능입니다.
//@LoggingDecorator(
// requestLogLevel = LogLevel.INFO,
// successfulResponseLogLevel = LogLevel.INFO
//)
public class HelloService {
@Get("/hello")
public String hello() {
throw new IllegalStateException("exception occurred");
}
}
따라서 유저는 exception을 확인하기 위해서 LoggingService를 등록해야 합니다. LoggingService가 등록되면 정상적으로 exception이 등록됩니다.
@LoggingDecorator(
requestLogLevel = LogLevel.INFO,
successfulResponseLogLevel = LogLevel.INFO
)
public class HelloService {
@Get("/hello")
public String hello() {
throw new IllegalStateException("exception occurred");
}
}
별도의 LoggingService를 등록하지 않으면 exception을 확인할 수 없는 불편함을 해소하기 위해 armeria 팀은 다음과 같은 issue를 등록했고 저는 해당 issue를 작업하기로 했습니다.
https://github.com/line/armeria/issues/4324
No uncaught service exceptions are logged out of the box. · Issue #4324 · line/armeria
When a new user writes an Armeria server, the user often doesn't realize they have to add LoggingService to see the actual exception in the log. This default behavior can be very confusing. It ...
github.com
Contribution 과정
오픈소스에 기여하는 게 처음인지라 모든 게 어색했습니다. 일단 관련 issue를 파악하고 어떻게 해결해 나가야 하는지 하나하나 생각해 봤습니다. 그 과정에서 armeria maintainer 분들의 적극적인 지원 덕에 어떻게 issue를 해결할 수 있는지 방향을 잡을 수 있었습니다. 해당 issue는 다음과 같은 방법으로 해결했습니다.
- LoggingService가 등록된 AnnotatedService에 대해서는 exception이 처리된 것으로 간주할 수 있도록 별도의 변수를 설정
- ExceptionReportingServerErrorHandler 클래스를 추가함으로써 처리되지 않은 exception이 존재하는 경우 일정한 주기로 로그를 출력
- Micrometer의 MeterRegistry에 서버가 시작된 이후 발생한 처리되지 않은 exception의 총개수를 확인할 수 있는 지표를 추가
- 처리되지 않은 exception을 일정한 주기로 로그를 출력할 때 해당 주기를 설정하거나 또는 로그 출력 기능을 off 할 수 있는 방법을 제공(JVM flag 또는 ServerBuilder)
오픈소스에 기여하는 과정에서 제가 가장 중요하다고 생각하는 점은 maintainer와의 소통입니다. Maintainer와 적극적으로 소통하다 보면 작업을 어떻게 수행할지 팁을 얻을 수 있고 작업 효율을 높일 수 있습니다. 또한 작업에서 놓치는 부분을 확인받는 것뿐 아니라 성능적인 면에서 어떻게 최적화할 수 있는지 팁도 얻을 수 있습니다.
해당 기능을 추가하는 과정이 순탄하지는 않았지만 maintainer 분들의 적극적인 지원 덕에 무사히 완료할 수 있었습니다. 해당 PR은 코멘트가 거의 200개.... 가 달렸지만 그 과정에서 배운 점이 정말 많은 것 같아 보람찬 작업이었습니다.
https://github.com/line/armeria/pull/4687
Add `ExceptionReportingServerErrorHandler` to log unhandled exceptions by seonwoo960000 · Pull Request #4687 · line/armeria
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 ...
github.com
결과
만약 유저가 LoggingService를 등록하지 않고 일정한 주기동안 발생한 exception이 따로 처리되지 않았다면 해당 exception에 대한 정보를 다음과 같이 출력합니다. 해당 기능은 JVM flag 또는 ServerBuilder를 통해서 설정할 수 있습니다.
Take away
기능을 추가하는 과정에서 제가 새로 배운 정보에 대해 공유해보고자 합니다. 관련 코드는 다음과 같습니다.
final class ExceptionReportingServerErrorHandler implements ServerErrorHandler, ServerListener {
private static final Logger logger = LoggerFactory.getLogger(ExceptionReportingServerErrorHandler.class);
// 1. Initialize only once
private static final AtomicIntegerFieldUpdater<ExceptionReportingServerErrorHandler> scheduledUpdater =
AtomicIntegerFieldUpdater.newUpdater(ExceptionReportingServerErrorHandler.class,
"scheduled");
private final Duration interval;
private final ServerErrorHandler delegate;
// Note: We keep both Micrometer Counter and our own counter because Micrometer Counter
// doesn't count anything if the MeterRegistry is a CompositeMeterRegistry
// without an actual MeterRegistry implementation.
private final Counter micrometerCounter;
// 2. LongAdder
private final LongAdder counter;
private long lastExceptionsCount;
private volatile int scheduled;
@Nullable
private ScheduledFuture<?> reportingTaskFuture;
@Nullable
private Throwable thrownException;
ExceptionReportingServerErrorHandler(MeterRegistry meterRegistry, ServerErrorHandler serverErrorHandler,
Duration interval) {
assert !interval.isNegative() && !interval.isZero() : interval;
this.interval = interval;
delegate = serverErrorHandler;
micrometerCounter = meterRegistry.counter("armeria.server.exceptions.unhandled", Tags.empty());
counter = new LongAdder();
}
/**
* Increments both {@link #micrometerCounter} and {@link #counter} and stores unhandled exception
* that occurs. If multiple servers use the same {@link MeterRegistry}, then {@link #micrometerCounter}
* will be shared across servers.
*/
@Nullable
@Override
public HttpResponse onServiceException(ServiceRequestContext ctx, Throwable cause) {
if (!ctx.shouldReportUnhandledExceptions()) {
return delegate.onServiceException(ctx, cause);
}
if ((cause instanceof HttpStatusException || cause instanceof HttpResponseException) &&
cause.getCause() != null) {
return delegate.onServiceException(ctx, cause);
}
// 3. Lazy initialization
if (reportingTaskFuture == null && scheduledUpdater.compareAndSet(this, 0, 1)) {
reportingTaskFuture = ctx.eventLoop().scheduleAtFixedRate(
this::reportException, interval.toMillis(), interval.toMillis(), TimeUnit.MILLISECONDS);
}
if (thrownException == null) {
thrownException = cause;
}
micrometerCounter.increment();
counter.increment();
return delegate.onServiceException(ctx, cause);
}
@Nullable
@Override
public AggregatedHttpResponse renderStatus(ServiceConfig config, @Nullable RequestHeaders headers,
HttpStatus status, @Nullable String description,
@Nullable Throwable cause) {
return delegate.renderStatus(config, headers, status, description, cause);
}
@Override
public void serverStarting(Server server) throws Exception {}
@Override
public void serverStarted(Server server) throws Exception {}
@Override
public void serverStopping(Server server) throws Exception {}
@Override
public void serverStopped(Server server) throws Exception {
if (reportingTaskFuture == null) {
return;
}
reportingTaskFuture.cancel(true);
reportingTaskFuture = null;
}
private void reportException() {
final long totalExceptionsCount = counter.sum();
final long newExceptionsCount = totalExceptionsCount - lastExceptionsCount;
if (newExceptionsCount == 0) {
return;
}
final Throwable exception = thrownException;
if (exception != null) {
logger.warn("Observed {} unhandled exceptions in last {}. " +
"Please consider adding the LoggingService decorator to get detailed error logs. " +
"One of the thrown exceptions:",
newExceptionsCount, TextFormatter.elapsed(interval.toNanos()), exception);
thrownException = null;
} else {
logger.warn("Observed {} unhandled exceptions in last {}. " +
"Please consider adding the LoggingService decorator to get detailed error logs.",
newExceptionsCount, TextFormatter.elapsed(interval.toNanos()));
}
lastExceptionsCount = totalExceptionsCount;
}
}
1. Initialize only once
처리되지 않은 exception을 로깅하는 schedule은 단 한 번만 수행돼야 합니다. 여러 스레드에서 해당 schedule을 등록하는 시나리오를 고려하기 위해서 AtomicIntegerFieldUpdater을 사용했습니다. 해당 기능의 compareAndSet 메서드를 통해 하나의 스레드에서만 scheduling이 가능하도록 설정했습니다.
2.LongAdder
여러 스레드에서 동시에 접근하여 값을 증가시켜야 하는 경우에 LongAdder을 사용할 수 있습니다. LongAdder은 AtomicLong보다 더 많은 increment 요청을 처리할 수 있습니다. LongAdder는 내부적으로 여러 counter으로 구성되고 해당 counter가 서로 다른 스레드에 할당되는 원리를 통해 AtomicLong 보다 더 높은 처리량을 가질 수 있습니다.
3. Lazy initialization
유저가 사용하지 않을 수 있는 기능에 대해서는 lazy initialization을 통해 불필요한 오버헤드를 줄일 수 있습니다. 새로 추가하는 기능은 일정한 주기로 처리되지 않은 exception을 로깅하기 위해 event loop에 schedule을 등록합니다. 하지만 모든 exception이 처리되는 중이라면 굳이 schedule이 등록될 필요가 없습니다. 이를 위해 제가 추가한 ExceptionReportingServerErrorHandler는 서버가 시작될 때 schedule을 등록하지 않고 가장 처음으로 처리되지 않은 exception이 발생할 때 schedule을 등록합니다.
4. final
변하지 않을 변수 그리고 extend 되지 않을 클래스에 대해서는 final을 붙입니다. 이는 불변성을 어느 정도 보장하는 것뿐 아니라 해당 값이 어떻게 변할지 지속적으로 생각하지 않아도 되기 때문에 개발자의 인지적 과부하를 줄일 수 있습니다.
결론
오픈소스를 기여하는 과정에는 난관이 많습니다. 하지만 난관을 헤쳐나가는 과정에서 배우는 게 무수히 많고 기존 업무와 다른 방식의 PR 리뷰를 받을 수 있다는 점이 제게 있어 소중한 경험이었습니다. 앞으로도 꾸준히 오픈소스에 기여해 제 자신의 기술력을 높이고자 합니다.