WildFly SwarmのログをLogstashに突っ込む

WildFly Swarmには、Logstash用のFractionがあります。こちらを使うと、アプリケーションやWildFly Swarm自身が
出力するログを、Logstashに送ることができるようです。

追加設定自体は、Maven依存関係を加えることと、

<dependency>
  <groupId>org.wildfly.swarm</groupId>
  <artifactId>logstash</artifactId>
</dependency>

Logstashの接続先を必要に応じて設定することくらいみたいなので、簡単に試してみましょう。
※それにしても、Logstash側のpipeline設定のサンプルくらいあってもいい気がしますが…

お題としては、簡単なJAX-RSリソースとCDI管理Beanを作成し、処理中にログ出力した内容が
Logstash経由でElasticsearchに投入されることを確認してみます。

準備

Mavenのpom.xmlは、このような感じで。WAR形式でいきます。
pom.xml

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>org.littlewings</groupId>
    <artifactId>logstash</artifactId>
    <version>0.0.1-SNAPSHOT</version>
    <packaging>war</packaging>

    <properties>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
        <maven.compiler.source>1.8</maven.compiler.source>
        <maven.compiler.target>1.8</maven.compiler.target>
        <scala.major.version>2.12</scala.major.version>
        <scala.version>${scala.major.version}.1</scala.version>
        <scala.maven.plugin.version>3.2.2</scala.maven.plugin.version>

        <failOnMissingWebXml>false</failOnMissingWebXml>

        <wildfly.swarm.version>2016.12.1</wildfly.swarm.version>
    </properties>

    <dependencyManagement>
        <dependencies>
            <dependency>
                <groupId>org.wildfly.swarm</groupId>
                <artifactId>bom</artifactId>
                <version>${wildfly.swarm.version}</version>
                <scope>import</scope>
                <type>pom</type>
            </dependency>
        </dependencies>
    </dependencyManagement>

    <dependencies>
        <dependency>
            <groupId>org.scala-lang</groupId>
            <artifactId>scala-library</artifactId>
            <version>${scala.version}</version>
        </dependency>

        <dependency>
            <groupId>javax</groupId>
            <artifactId>javaee-api</artifactId>
            <version>7.0</version>
            <scope>provided</scope>
        </dependency>

        <dependency>
            <groupId>org.wildfly.swarm</groupId>
            <artifactId>jaxrs</artifactId>
        </dependency>
        <dependency>
            <groupId>org.wildfly.swarm</groupId>
            <artifactId>cdi</artifactId>
        </dependency>
        <dependency>
          <groupId>org.wildfly.swarm</groupId>
          <artifactId>logstash</artifactId>
        </dependency>
    </dependencies>

    <build>
        <plugins>
            <plugin>
                <groupId>net.alchim31.maven</groupId>
                <artifactId>scala-maven-plugin</artifactId>
                <version>${scala.maven.plugin.version}</version>
                <executions>
                    <execution>
                        <goals>
                            <goal>compile</goal>
                            <goal>testCompile</goal>
                        </goals>
                    </execution>
                </executions>
                <configuration>
                    <scalaVersion>${scala.version}</scalaVersion>
                    <args>
                        <arg>-Xlint</arg>
                        <arg>-unchecked</arg>
                        <arg>-deprecation</arg>
                        <arg>-feature</arg>
                    </args>
                    <recompileMode>incremental</recompileMode>
                </configuration>
            </plugin>
            <plugin>
                <groupId>org.wildfly.swarm</groupId>
                <artifactId>wildfly-swarm-plugin</artifactId>
                <version>${wildfly.swarm.version}</version>
                <executions>
                    <execution>
                        <goals>
                            <goal>package</goal>
                        </goals>
                    </execution>
                </executions>
            </plugin>
        </plugins>
    </build>
</project>

JAX-RSやらCDIやらのFractionを加えていますが、今回の注目はLogstashのFractionが
入っていることですね。

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

用意したアプリケーションは、単純に足し算をするもの。ただ、各処理にJBoss Loggingを使った
ログ出力をするようにしておきます。

JAX-RSリソースクラス。
src/main/scala/org/littlewings/wildflyswarm/logstash/CalcResource.scala

package org.littlewings.wildflyswarm.logstash

import javax.enterprise.context.ApplicationScoped
import javax.inject.Inject
import javax.ws.rs.core.{Context, MediaType, UriInfo}
import javax.ws.rs.{GET, Path, Produces, QueryParam}

import org.jboss.logging.Logger

@Path("calc")
@ApplicationScoped
class CalcResource {
  private[logstash] val logger: Logger = Logger.getLogger(getClass)

  @Inject
  private[logstash] var calcService: CalcService = _

  @GET
  @Path("add")
  @Produces(Array(MediaType.TEXT_PLAIN))
  def add(@QueryParam("a") a: Int, @QueryParam("b") b: Int, @Context uriInfo: UriInfo): Int = {
    // logger.debugf("url = %s, parameter a = %d, b = %d", uriInfo.getRequestUri, a, b)
    logger.infof("url = %s, parameter a = %d, b = %d", uriInfo.getRequestUri, a, b)
    calcService.add(a, b)
  }
}

CDI管理Bean。
src/main/scala/org/littlewings/wildflyswarm/logstash/CalcService.scala

package org.littlewings.wildflyswarm.logstash

import javax.enterprise.context.ApplicationScoped

import org.jboss.logging.Logger

@ApplicationScoped
class CalcService {
  private[logstash] val logger: Logger = Logger.getLogger(getClass)

  def add(a: Int, b: Int): Int = {
    logger.infof("parameter a = %d, b = %d", a, b)
    a + b
  }
}

Logstashへの接続設定

ドキュメントを参照すると、システムプロパティでLogstashへの接続設定（といってもホストと
ポートくらいですが）をすることができるようです。

今回は、project-stages.ymlに書いておくことにします。
src/main/resources/project-stages.yml

swarm:
    logging: INFO
    logstash:
        hostname: localhost
        port: 9300

ちなみに、この値はLogstashFractionのデフォルト値みたいです。

アプリケーションの方は、あとはパッケージングして動かすだけです。

ELKスタック（Elasticsearch／Logstash／Kibana）

続いて、動作確認を行うためのELKスタックを用意します。

Docker Composeで簡単に用意しましょう。
docker-compose/docker-compose.yml

elasticsearch:
  image: docker.elastic.co/elasticsearch/elasticsearch:5.1.1
  ports:
    - "9200:9200"
  container_name: elasticsearch
  hostname: elasticsearch
  environment:
    - "ES_JAVA_OPTS=-Xms1g -Xmx1g"
    - "http.host=0.0.0.0"
    - "transport.host=127.0.0.1"
    - "xpack.security.enabled=false"
logstash:
  image: docker.elastic.co/logstash/logstash:5.1.1
  ports:
    - "5044:5044"
    - "9300:9300"
    - "9600:9600"
  container_name: logstash
  links: 
    - elasticsearch
  volumes:
    - ./pipeline/:/usr/share/logstash/pipeline/:ro
kibana:
  image: docker.elastic.co/kibana/kibana:5.1.1
  ports:
    - "5601:5601"
  container_name: kibana
  links: 
    - elasticsearch

Kibanaはオマケ的にですが。

Logstashはホスト側のvolumeをマウントするようにしており、その中にpipelineの
設定を含めています。
docker-compose/pipeline/logstash.conf

input {
  tcp {
    port => 9300
  }
}

output {
  elasticsearch {
    hosts => ["elasticsearch:9200"]
  }
}

WildFly Swarmからのログは、TCPで受けるのがよさそうな感じです。

中身はSocketHandlerっぽいですからね。
https://github.com/wildfly-swarm/wildfly-swarm/blob/2016.12.1/fractions/logstash/src/main/java/org/wildfly/swarm/logstash/runtime/LogstashCustomizer.java

また、FormatterはJSONベースみたいです。
https://github.com/jamezp/jboss-logmanager-ext/blob/1.0.0.Alpha3/src/main/java/org/jboss/logmanager/ext/formatters/LogstashFormatter.java

ちょっと脱線しましたね。これで、ELKスタックを起動しましょう。

$ cd docker-compose
$ docker-compose up

動作確認

それでは、動作確認してみましょう。先ほど作成したアプリケーションを、パッケージングして
起動してみます。

$ mvn package
$ java -jar target/logstash-0.0.1-SNAPSHOT-swarm.jar

とりあえず、起動した時点で大量のログが入っているようです。

でも、ちょっと多い気がしますね…。起動しただけで、5,000くらいのログが入っています。

また、ログの本体は「message」のようですが、JSON文字列として入っているようです。

ちょっとこれでは読みづらいので、messageの部分をjson filterでパースしてみましょう。
json | Logstash Reference [5.1] | Elastic

input {
  tcp {
    port => 9300
  }
}

filter {
  json {
    source => "message"
  }
}

output {
  elasticsearch {
    hosts => ["elasticsearch:9200"]
  }
}

1度インデックスを削除してから、アプリケーションを再起動してもう1度登録すると、だいぶ見やすくなります。

ただ、ログは大量に保存されたままです。これは、TRACEレベルのログなども含めて全部
放り込まれているからみたいですね。

swarm.loggingで指定したレベルとは関係ないみたいなので、とりあえず全部のログ出力
イベントが入ってしまうのでしょう。

ということであれば、Logstash側で落としてみましょう。

filterでdropすればよさそうです。
drop | Logstash Reference [5.1] | Elastic

pipelineの設定ファイル中では、ifも書けるみたいですし。
Event Dependent Configuration / Conditionals

input {
  tcp {
    port => 9300
  }
}

filter {
  json {
    source => "message"
  }

  if [level] == "DEBUG" or [level] == "TRACE" {
    drop { }
  }
}

output {
  elasticsearch {
    hosts => ["elasticsearch:9200"]
  }
}

再度インデックスを作り直してみると、だいぶ量が絞られます。

触りはじめとしては、こんな感じではないでしょうか。

って、自分の書いたコードの動作確認してませんでしたね。

$ curl 'http://localhost:8080/calc/add?a=5&b=3'
8
$ curl 'http://localhost:8080/calc/add?a=8&b=9'
17

ちゃんと入っているみたいです。

まとめ

WildFly SwarmのLogstash Fractionを試してみました。

まだ自分にLogstash自体の勘所もないので、ちゃんと動かすまではそこそこ苦労しましたが、
1度設定できてしまえばあとはなんとかなりそうな感じがします。

それにしても、Logstash Fractionを設定してしまうと、起動後は通常のログがコンソールに出なく
なるのですが…ログ出力（Handler）設定、もうちょっと設定できるようにならないかなぁと。
特にYAMLで。

あと、TRACEとかDEBUGログがとりあえずLogstashに送られてしまうの、設定したい…のですが、
Fractionを書かないと厳しそうですねー。
https://github.com/wildfly-swarm/wildfly-swarm/blob/2016.12.1/fractions/logstash/src/main/java/org/wildfly/swarm/logstash/runtime/LogstashCustomizer.java#L61

今回作成したコードは、こちらに置いています。
https://github.com/kazuhira-r/wildfly-swarm-scala-examples/tree/master/logstash

CLOVER🍀

That was when it all began.

WildFly SwarmのログをLogstashに突っ込む

準備

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

Logstashへの接続設定

ELKスタック（Elasticsearch／Logstash／Kibana）

動作確認

まとめ