Sentry JavaのLogbackインテグレーションを試す

$ java -version
openjdk version "11.0.4" 2019-07-16
OpenJDK Runtime Environment (build 11.0.4+11-post-Ubuntu-1ubuntu218.04.3)
OpenJDK 64-Bit Server VM (build 11.0.4+11-post-Ubuntu-1ubuntu218.04.3, mixed mode, sharing)


$ mvn -version
Apache Maven 3.6.1 (d66c9c0b3152b2e69ee9bac180bb8fcc8e6af555; 2019-04-05T04:00:29+09:00)
Maven home: $HOME/.sdkman/candidates/maven/current
Java version: 11.0.4, vendor: Ubuntu, runtime: /usr/lib/jvm/java-11-openjdk-amd64
Default locale: ja_JP, platform encoding: UTF-8
OS name: "linux", version: "4.15.0-58-generic", arch: "amd64", family: "unix"

Sentryは、オンプレミス版（Docker）を使用します。バージョンは、9.1.2。

Installation with Docker - Docs

GitHub - getsentry/onpremise: Sentry On-Premise setup

インストール時に作成するアカウントは、「test@example.com / password」としました。

お題

シンプルに、LogbackからSentryにログを送信し、Sentry上で確認できることを目標にします。

また、今回はアラートまわりについては扱いません。

準備

アプリケーションの、Maven依存関係はこちら。

        <dependency>
            <groupId>io.sentry</groupId>
            <artifactId>sentry-logback</artifactId>
            <version>1.7.27</version>
        </dependency>

「sentry-logback」を依存関係に追加すると、推移的に「slf4j-api」も引き込まれます。

Sentryにログインして、プロジェクトを作成します。Javaを選択。

f:id:Kazuhira:20190823001546p:plain

プロジェクトの「Settings」から、「DSN」を確認。

f:id:Kazuhira:20190823001617p:plain

このDSNを覚えておきます。

サンプルアプリケーション

ドキュメントを見ていると、スタックトレースがそれなりの深さがあるものを用意した方が良さそうだったので、今回は
簡単なHTTPサーバーを書くことにしました。

JDKに組み込まれている、HttpServerを利用して作成。
src/main/java/org/littlewings/sentry/logback/Server.java

package org.littlewings.sentry.logback;

import java.io.IOException;
import java.net.InetSocketAddress;
import java.nio.charset.StandardCharsets;

import com.sun.net.httpserver.HttpServer;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;

public class Server {
    public static void main(String... args) throws IOException {
        Logger logger = LoggerFactory.getLogger(Server.class);

        HttpServer server = HttpServer.create(new InetSocketAddress(8080), 10);
        server.createContext("/", exchange -> {
            MDC.put("app", "java-app");

            String path = exchange.getRequestURI().getPath();

            logger.info("{} access", path);

            byte[] body;
            switch (path) {
                case "/info":
                    logger.info("INFOログだよ");

                    body = "OK!!".getBytes(StandardCharsets.UTF_8);
                    exchange.sendResponseHeaders(200, body.length);
                    exchange.getResponseBody().write(body);
                    break;
                case "/warn":
                    logger.warn("WARNログです");

                    body = "WARN!!".getBytes(StandardCharsets.UTF_8);
                    exchange.sendResponseHeaders(500, body.length);
                    exchange.getResponseBody().write(body);
                    break;
                case "/error":
                    logger.error("エラーですよ");

                    body = "ERROR!!".getBytes(StandardCharsets.UTF_8);
                    exchange.sendResponseHeaders(500, body.length);
                    exchange.getResponseBody().write(body);
                    break;
                case "/exception":
                    logger.error("例外だよ", new RuntimeException("Oops!!"));

                    body = "Oops!!".getBytes(StandardCharsets.UTF_8);
                    exchange.sendResponseHeaders(500, body.length);
                    exchange.getResponseBody().write(body);
                    break;
                default:
                    exchange.sendResponseHeaders(404, 0);
                    break;
            }

            MDC.clear();
        });

        server.start();
    }
}

「/info」や「/warn」などのエンドポイントに合わせたログレベルのログを出力し、「/exceptioon」の場合は例外をロギング。

次に、ドキュメントを見ながらLogbackの設定ファイルを用意します。

Logback / Usage

src/main/resources/logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%-5level] [%X{app}] %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>

    <appender name="Sentry" class="io.sentry.logback.SentryAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>WARN</level>
        </filter>
    </appender>

    <root level="info">
        <appender-ref ref="STDOUT"/>
        <appender-ref ref="Sentry"/>
    </root>
</configuration>

Appenderとして、「SentryAppender」を追加します。ログレベルは、今回はドキュメント通りにWARN以上を対象にしました。

    <appender name="Sentry" class="io.sentry.logback.SentryAppender">
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>WARN</level>
        </filter>
    </appender>

また、Sentry Javaの設定ファイルも用意。
src/main/resources/sentry.properties

environment=staging
servername=myhost

mdctags=app
stacktrace.app.packages=org.littlewings.sentry.logback

設定の意味は、こちらを。

Configuration - Docs

environmentやservernameは、Optionとして定義してあります。

Options

servernameは、イベントが発生したホスト名をこちらで上書きできるようです。Optionとしてなにも指定しなかった場合は、アプリケーションを
実行しているホスト名がSentryに送信されます。

Tags、MDC Tagsというものもあり、タグを設定することができます。

動作確認

と、設定の説明はこれくらいにして試してみましょう。

DSNを指定して、起動。

$ mvn compile exec:java -Dexec.mainClass=org.littlewings.sentry.logback.Server -Dsentry.dsn=http://9f72660300424abf915b9cc317ad95@localhost:9000/2

「/info」。

$ curl localhost:8080/info
OK!!


### 出力されたログ
2019-08-24 00:34:20.089 [HTTP-Dispatcher] [INFO ] [java-app] org.littlewings.sentry.logback.App - /info access
2019-08-24 00:34:20.091 [HTTP-Dispatcher] [INFO ] [java-app] org.littlewings.sentry.logback.App - INFOログだよ

「/warn」。

$ curl localhost:8080/warn
WARN!!


2019-08-24 00:34:47.319 [HTTP-Dispatcher] [INFO ] [java-app] org.littlewings.sentry.logback.App - /warn access
2019-08-24 00:34:47.319 [HTTP-Dispatcher] [WARN ] [java-app] org.littlewings.sentry.logback.App - WARNログです

「/error」。

$ curl localhost:8080/error
ERROR!!


2019-08-24 00:35:08.984 [HTTP-Dispatcher] [INFO ] [java-app] org.littlewings.sentry.logback.App - /error access
2019-08-24 00:35:08.985 [HTTP-Dispatcher] [ERROR] [java-app] org.littlewings.sentry.logback.App - エラーですよ

「/exception」。

$ curl localhost:8080/exception
Oops!!


2019-08-24 00:35:40.262 [HTTP-Dispatcher] [INFO ] [java-app] org.littlewings.sentry.logback.App - /exception access
2019-08-24 00:35:40.264 [HTTP-Dispatcher] [ERROR] [java-app] org.littlewings.sentry.logback.App - 例外だよ
java.lang.RuntimeException: Oops!!
    at org.littlewings.sentry.logback.Server.lambda$main$0(Server.java:48)
    at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:77)
    at jdk.httpserver/sun.net.httpserver.AuthFilter.doFilter(AuthFilter.java:82)
    at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:80)
    at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange$LinkHandler.handle(ServerImpl.java:692)
    at jdk.httpserver/com.sun.net.httpserver.Filter$Chain.doFilter(Filter.java:77)
    at jdk.httpserver/sun.net.httpserver.ServerImpl$Exchange.run(ServerImpl.java:664)
    at jdk.httpserver/sun.net.httpserver.ServerImpl$DefaultExecutor.execute(ServerImpl.java:159)
    at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.handle(ServerImpl.java:442)
    at jdk.httpserver/sun.net.httpserver.ServerImpl$Dispatcher.run(ServerImpl.java:408)
    at java.base/java.lang.Thread.run(Thread.java:834)

さて、Sentryの方を見てみましょう。

見た目としては2つ、イベントとしては3つ来ています。

f:id:Kazuhira:20190824003743p:plain