2021-01-29

makeを学んでみる

Linux Go

これは、なにをしたくて書いたもの？

Goでのビルドツールは、makeを使うことが多いと聞いたので。

いくつか、Goで書かれた有名なOSSを見てみると、確かにMakefileが置かれています。

https://github.com/prometheus/prometheus/blob/v2.24.1/Makefile

https://github.com/hashicorp/terraform/blob/v0.14.5/Makefile

https://github.com/moby/moby/blob/v20.10.2/Makefile

https://github.com/kubernetes/kubernetes/blob/v1.20.2/build/root/Makefile

Goの勉強を始めていることですし、これを機に少し覚えてみようかな、と。

make自体は使ったことがあります。ただ、すでに用意されているMakefileと手順に従い、make、make installとかを
実行してきただけですね。

環境

今回の環境は、こちらです。

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 20.04.1 LTS
Release:    20.04
Codename:   focal


$ uname -srvmpio
Linux 5.4.0-65-generic #73-Ubuntu SMP Mon Jan 18 17:25:17 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

make自体は、インストール済みです。

$ make --version
GNU Make 4.2.1
このプログラムは x86_64-pc-linux-gnu 用にビルドされました
Copyright (C) 1988-2016 Free Software Foundation, Inc.
ライセンス GPLv3+: GNU GPL バージョン 3 以降 <http://gnu.org/licenses/gpl.html>
これはフリーソフトウェアです: 自由に変更および配布できます.
法律の許す限り、　無保証　です.

make

makeについて見ていくということで、まずは一次リソースをあたりましょう。

GNUプロジェクトを見に行きます。

Software - GNU Project - Free Software Foundation

こちらにmakeの説明があります。ちょっと概要を見てみましょう。正確には、GNU Makeですね。

Make - GNU Project - Free Software Foundation

makeは、プログラムのソースファイルから、実行可能ファイルやその他の非ソースファイルの生成をコントロールするツールです。
プログラムをビルドするための方法は、makefileと呼ばれるファイルに記述します。

makeの機能は、以下になります。

パッケージのビルド方法やインストール方法がmakefileに記述されているため、ユーザーは詳細を知らなくてもこれらのタスクを実行できる
makeはファイルの更新を把握し、前回のビルドから変更があったファイルに基づいて処理を行い、必要なファイルを更新する
言語非依存で、makefile内で指定されたシェルコマンドを実行する
makeはパッケージの作成以外にも、インストールやアンインストールなど、様々な処理を行わせることができる

makefileには、ソースコードからビルド結果を生成するための、一連のルールを書きます。この時、ルールには依存関係を持たせる
ことができます。

以下は、簡単なルールの構文です。

target:   dependencies ...
          commands
          ...

makefile内にはルール（target）を書き、makeでどのルールを実行するかを指定することができます。

…というのが、基本的な話のようですね。

makeについての詳細は、マニュアルを見ていくことになります。

GNU Make Manual - GNU Project - Free Software Foundation

https://www.gnu.org/software/make/manual/make.html

では、これらを見ながら簡単に試していってみましょう。

How to Read This Manual

If you are new to make, or are looking for a general introduction, read the first few sections of each chapter, skipping the later sections.

はい。

The exception is the second chapter, An Introduction to Makefiles, all of which is introductory.

つまり、初めての人は2章を読みなさいということのようです。

An Introduction to Makefiles

はじめてのMakefile

というわけで、こちらを見ながら始めていきます。

An Introduction to Makefiles

単純なmakefileは、以下のようなシンプルなルールで構成されます。

target … : prerequisites …
        recipe
        …
        …

What a Rule Looks Like

ここで、ターゲット（target）には実行可能ファイルの名前やオブジェクトファイル、アクションの名前を指定します。
main.o、clean、install、buildなどですね。

前提条件（prerequisites）として、別のターゲットを指定することができます。これはターゲット間の依存関係を
表します。

レシピ（recipe）は、このターゲットで実際に行う処理（コマンド）を記述します。

注意点として、レシピの先頭にはタブを配置する必要があります。

実際に、makefileを書いてみましょう。

Makefile

step1: step2 step4
    echo 1
    echo one

step2: step3
    echo 2

step3:
    echo 3 \
    three

step4:
    echo 'four!!'

A Simple Makefile

makefileはMakefileという名前でmakeコマンドは認識しますが、-fオプションで別の名前を指定することもできます。

step1はstep2、step4を前提にしていて、step2はstep3を前提にしています。step3には前提条件はありません。
step1には複数のコマンド（レシピ）を書いています。step3は、レシピを継続行にしています。

この状態で、makeコマンドを実行してみます。

$ make
echo 3 \
three
3 three
echo 2
2
echo 'four!!'
four!!
echo 1
1
echo one
one

step3 → step2 → step4 → step1という実行順になりました。

なんとなく、依存関係を解決しつつ実行しているのがわかると思います。

makeコマンドの引数としてターゲットを指定することで、各ターゲット単位（と依存するターゲット）ごとにも実行できます。

$ make step3
echo 3 \
three
3 three


$ make step4
echo 'four!!'
four!!


$ make step2
echo 3 \
three
3 three
echo 2
2

ところで、単にmakeと指定した時は、step1のターゲットが実行されたように思います。

この理由は、以下に書いてあります。

By default, make starts with the first target (not targets whose names start with ‘.’). This is called the default goal.

How make Processes a Makefile

つまり、最初のターゲットが実行されるようです。これをデフォルトゴールと呼びます、と。

これをオーバーライドする方法として、コマンドの引数で指定する方法（先ほど使った方法）と.DEFAULT_GOALという特殊変数を
使う方法があるようです。

You can override this behavior using the command line (see Arguments to Specify the Goals) or with the .DEFAULT_GOAL special variable (see Other Special Variables).

試しに、.DEFAULT_GOALを指定してみましょう。

Makefile

.DEFAULT_GOAL := step4

step1: step2 step4
    echo 1
    echo one

step2: step3
    echo 2

step3:
    echo 3 \
    three

step4:
    echo 'four!!'

確認。

$ make
echo 'four!!'
four!!

明示的にターゲットを指定しない場合に、実行されるターゲットが変わりましたね。

ビルドで使うようなmakefileの例を見てみると、ターゲットの名前はファイル名になっていたりします。

A Simple Makefile

edit : main.o kbd.o command.o display.o \
       insert.o search.o files.o utils.o
        cc -o edit main.o kbd.o command.o display.o \
                   insert.o search.o files.o utils.o

main.o : main.c defs.h
        cc -c main.c
kbd.o : kbd.c defs.h command.h
        cc -c kbd.c
command.o : command.c defs.h command.h
        cc -c command.c
display.o : display.c defs.h buffer.h
        cc -c display.c
insert.o : insert.c defs.h buffer.h
        cc -c insert.c
search.o : search.c defs.h buffer.h
        cc -c search.c
files.o : files.c defs.h buffer.h command.h
        cc -c files.c
utils.o : utils.c defs.h
        cc -c utils.c
clean :
        rm edit main.o kbd.o command.o display.o \
           insert.o search.o files.o utils.o

makefileは、このファイル名をターゲットにすることで依存関係を表現します。

今回作成したstep1のようなターゲットは、ファイルではありません。上記の例だとcleanがそうですね。

このようなファイルではないターゲットをPhonyターゲットと呼ぶそうです。

Phony Targets

Phonyターゲットは、ファイル名ではないターゲットのことです。これを使う理由は、同じ名前のファイルとの競合を回避するためと、
パフォーマンスの向上のためです。

レシピがターゲットとなるファイルを作成しない場合、ターゲットが再作成される度にレシピが実行されるようです。
また、ターゲットと同じ名前のファイルがあるとうまく機能しなくなるようです。

とすると、今回のmakefileはすべてPhonyターゲットなので、以下のようにするのが正解でしょうね。

Makefile

# .DEFAULT_GOAL := step4

.PHONY: step1
step1: step2 step4
    echo 1
    echo one

.PHONY: step2
step2: step3
    echo 2

.PHONY: step3
step3:
    echo 3 \
    three

.PHONY: step4
step4:
    echo 'four!!'

変数を使う

makefile内では、変数を使うこともできます。

Variables Make Makefiles Simpler

こんな感じで、=で定義します。参照は$(変数)です。

Makefile

ECHO_COMMAND = echo
MESSAGE = 'Hello World'

.PHONY: hello
hello:
    $(ECHO_COMMAND) $(MESSAGE)

確認。

$ make
echo 'Hello World'
Hello World

ちなみに、この変数は外部から上書きすることもできます。

$ make MESSAGE=hello
echo hello
hello

これは、makeコマンド自身に上書きしてもらっています。

環境変数で上書きする場合は、単純に指定しただけではダメです。

$ MESSAGE=hello make
echo 'Hello World'
Hello World

-eオプションを付ける必要があります。

$ MESSAGE=hello make -e
echo hello
hello

Variables from the Environment

変数については、ドキュメントのこのあたりを見ましょう。

How to Use Variables

また、自動で定義される変数もあります。

Automatic Variables

Goプロジェクトでmakefileを書いてみる

最後にGoプロジェクトで簡単に試してみましょう。

Goのバージョン。

$ go version
go version go1.15.7 linux/amd64

プロジェクト作成。

$ go mod init app
go: creating new go.mod: module app

go.mod

module app

go 1.15

ソースコードを作成。

main.go

package main

import (
    "fmt"
)

func main() {
    fmt.Println(GetMessage())
}

func GetMessage() string {
    return "Hello World!!"
}

テストコードも作成。

main_test.go

package main

import (
    "testing"
)

func TestGetMessage(t *testing.T) {
    if GetMessage() != "Hello World!!" {
        t.Error("test failed!")
    }
}

makefileも書きます。

Makefile

EXECUTABLE_FILE = app

.PHONY: build
build: format lint test
    go build

.PHONY: run
run: format
    go run main.go

.PHONY: format
format:
    gofmt -w -d .

.PHONY: lint
lint:
    go vet ./...

.PHONY: test
test:
    go test ./...

.PHONY: clean-testcache
clean-testcache:
    go clean -testcache

.PHONY: clean
clean:
    rm $(EXECUTABLE_FILE)

デフォルトでは、buildターゲットを実行します。ターゲットの依存関係から、フォーマットしてgo vetをかけて、テストを実行して
実行可能ファイルの生成まで行います。

$ make
gofmt -w -d .
go vet ./...
go test ./...
ok      app 0.002s
go build

できあがったファイルの実行。

$ ./app 
Hello World!!

clean。こちらは単発のターゲットです。

$ make clean
rm app

run。フォーマットとプログラムの実行が含まれます。

$ make run
gofmt -w -d .
go run main.go
Hello World!!

依存するターゲットを順次実行している途中で、あるターゲットが失敗するとそこで停止します。たとえば、今回のデフォルトターゲットを
実行して、go testが失敗した場合はこんな感じになります。

$ make
gofmt -w -d .
go vet ./...
go test ./...
--- FAIL: TestGetMessage (0.00s)
    main_test.go:9: test failed!
FAIL
FAIL    app 0.002s
FAIL
make: *** [Makefile:21: test] エラー 1

また、-nを付けると実際には処理を行わずにどのようなターゲットが実行されるかを表示してくれます。

$ make -n
gofmt -w -d .
go vet ./...
go test ./...
go build


$ make -n test
go test ./...


$ make -n run
gofmt -w -d .
go run main.go

なんとなく、雰囲気はわかった気がします。

あとはOSSで使われているmakefileを眺めたりして、覚えていきましょう。

2021-01-28

Fluentdで複数行のログを読む

Fluentd

これは、なにをしたくて書いたもの？

以前、Fluent Bitで複数行（Multiline）のログファイルを読むエントリを書きました。

Fluent Bitで、複数行のログファイルを読む - CLOVER🍀

今回は、これをFluentdで行ってみます。

FluentdとMultiline

Fluentdを使って複数行のログを読むには、2つの方法があるようです。

Fluentd単体だと、Parser Pluginのmultilineを使います。

multiline - Fluentd

サードパーティ製のプラグインを使う場合は、fluentd-plugin-concatを使います。

GitHub - fluent-plugins-nursery/fluent-plugin-concat: Fluentd Filter plugin to concatenate multiline log separated in multiple events.

今回、これらを使って複数行のログを読んでみたいと思います。

ログを出力するサンプルアプリケーションは、Fluent Bitの時と同じもの（Spring Bootのバージョンだけ上げます）を使います。

Fluent Bitで、複数行のログファイルを読む - CLOVER🍀

以下、それぞれの方法の概要を。

Parser Plugin / multiline

まずは、multiline Parser Pluginを使う方法から。

multiline - Fluentd

他のParser Pluginと異なり、Tail Pluginと組み合わせて使うことが想定されています。

Unlike other parser plugins, this plugin needs special code in input plugin e.g. handle format_firstline. So, currently, in_tail plugin works with multiline but other input plugins do not work with it.

パラメーターは2種類で、format_firstlineとformatN（Nは数字）です。

少なくとも、format1は必須になります。1以降のformatNは、複数行で構成された各ログをより細かくパターンマッチさせる時に
使います。

Railsのログの例が、その活用例になっています。

multiline / Rails Log

format_firstlineは、複数行の開始を表す正規表現パターンを指定します。デフォルトはnilで、指定した場合はこのパターンに
マッチしない行をバッファに溜めていくようになります。

再度format_firstlineにマッチする行が来たら、その直前までがひとつのログレコードとして扱われることになります、と。

Javaのスタックトレースの例が、format_firstlineとformat1だけを指定してひとつにまとめる例としてはわかりやすいですね。
これがドキュメントに記載されています。

multiline / Java Stacktrace Log

ソースコードで見ると、確かにTail Pluginがmultilineを完全意識した構成になっていますね。

https://github.com/fluent/fluentd/blob/v1.11.2/lib/fluent/plugin/in_tail.rb#L519-L556

また、Multiline Pluginのパース処理そのものにはformat_firstlineの方は出てこないようです。format_firstlineを意識しているのは、
あくまでTail Pluginのようですね。

https://github.com/fluent/fluentd/blob/v1.11.2/lib/fluent/plugin/parser_multiline.rb#L76-L100

つまり、formatNのみを使った場合は複数行ログの行数が想定できることになります、と。

fluent-plugin-concat

続いて、fluent-plugin-concatです。こちらはFilter Pluginとして使う、複数のイベントに分割されたログを結合するためのものです。

GitHub - fluent-plugins-nursery/fluent-plugin-concat: Fluentd Filter plugin to concatenate multiline log separated in multiple events.

複数行の指定方法はいくつかあり、n_lines、multiline_start_regexp、multiline_end_regexp、continuous_line_regexpが
あります。n_linesと他の設定には、排他の関係があります。

それぞれ意味はわかりそうですが、n_linesが複数行がどれだけ続くか、他は複数行の開始、終了、継続を表す正規表現を
指定するといった感じですね。

使い方も書かれていますが、特にDockerとKubernetesがとてもしっかり書かれています。これらでよく使われるんでしょうね…。

Usage

このFilter Pluginが複数のタグにマッチする場合、ログが混ざったりするのでは？と思ったのですが、デフォルトでタグごとに
ストリームの管理が分かれているようです。

https://github.com/fluent-plugins-nursery/fluent-plugin-concat/blob/v2.4.0/lib/fluent/plugin/filter_concat.rb#L177-L188

さらに細かくストリームの単位を指定したい場合は、stream_identity_keyでレコード内でどのキーをストリームの単位として
扱うかを指定します。

説明はこれくらいにして、実際に使ってみましょう。

環境

今回の環境は、こちらです。

$ td-agent --version
td-agent 1.11.2


$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 20.04.1 LTS
Release:    20.04
Codename:   focal


$ uname -srvmpio
Linux 5.4.0-65-generic #73-Ubuntu SMP Mon Jan 18 17:25:17 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

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

まずは、ログを読み込む対象となるサンプルアプリケーションを用意します。Spring Bootで、簡単に作成。

JavaとMavenのバージョン。

$ java --version
openjdk 11.0.9.1 2020-11-04
OpenJDK Runtime Environment (build 11.0.9.1+1-Ubuntu-0ubuntu1.20.04)
OpenJDK 64-Bit Server VM (build 11.0.9.1+1-Ubuntu-0ubuntu1.20.04, mixed mode, sharing)


$ mvn --version
Apache Maven 3.6.3 (cecedd343002696d0abb50b32b541b8a6ba2883f)
Maven home: $HOME/.sdkman/candidates/maven/current
Java version: 11.0.9.1, vendor: Ubuntu, runtime: /usr/lib/jvm/java-11-openjdk-amd64
Default locale: ja_JP, platform encoding: UTF-8
OS name: "linux", version: "5.4.0-64-generic", arch: "amd64", family: "unix"

`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>simple-logging-web-app</artifactId>
    <version>0.0.1-SNAPSHOT</version>

    <properties>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
        <maven.compiler.source>11</maven.compiler.source>
        <maven.compiler.target>11</maven.compiler.target>
    </properties>

    <dependencyManagement>
        <dependencies>
            <dependency>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-dependencies</artifactId>
                <version>2.4.2</version>
                <type>pom</type>
                <scope>import</scope>
            </dependency>
        </dependencies>
    </dependencyManagement>

    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
        </dependency>
    </dependencies>

    <build>
        <finalName>${project.artifactId}</finalName>
        <plugins>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
                <version>2.4.2</version>
                <executions>
                  <execution>
                    <goals>
                      <goal>repackage</goal>
                    </goals>
                  </execution>
                </executions>
            </plugin>
        </plugins>
    </build>
</project>

ログを出力するだけの、@RestController。

src/main/java/org/littlewings/spring/example/App.java

package org.littlewings.spring.example;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.boot.SpringApplication;
import org.springframework.boot.autoconfigure.SpringBootApplication;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;

@SpringBootApplication
@RestController
@RequestMapping("app")
public class App {
    Logger logger = LoggerFactory.getLogger(App.class);

    public static void main(String... args) {
        SpringApplication.run(App.class, args);
    }

    @GetMapping("info")
    public String info() {
        logger.info("{}, info logging", "hello");

        return "info logging";
    }

    @GetMapping("warn")
    public String warn() {
        logger.warn("{}, warn logging", "world");

        return "warn logging";
    }

    @GetMapping("error")
    public String error() {
        logger.error("{}, error logging", "oops!!");

        return "error logging";
    }

    @GetMapping("exception")
    public String exception() {
        Exception e = new RuntimeException("Oops!!");

        logger.error("exception occurred, {}", "why?", e);

        return "exception logging";
    }
}

パッケージングして

$ mvn package

起動。これで、/tmp/spring.logにログが出力されます。

$ java -Dlogging.file.path=/tmp -jar target/simple-logging-web-app.jar

確認。

$ curl localhost:8080/app/info
info logging


$ curl localhost:8080/app/error
error logging


$ curl localhost:8080/app/exception
exception logging

ログはこんな感じに出力されます。

2021-01-27 14:28:14.969  INFO 1263 --- [http-nio-8080-exec-1] org.littlewings.spring.example.App       : hello, info logging
2021-01-27 14:28:16.503 ERROR 1263 --- [http-nio-8080-exec-3] org.littlewings.spring.example.App       : oops!!, error logging
2021-01-27 14:28:17.895 ERROR 1263 --- [http-nio-8080-exec-2] org.littlewings.spring.example.App       : exception occurred, why?

java.lang.RuntimeException: Oops!!
    at org.littlewings.spring.example.App.exception(App.java:44) ~[classes!/:na]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na]
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
    at java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[na:na]
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197) ~[spring-web-5.3.3.jar!/:5.3.3]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141) ~[spring-web-5.3.3.jar!/:5.3.3]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106) ~[spring-webmvc-5.3.3.jar!/:5.3.3]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:894) ~[spring-webmvc-5.3.3.jar!/:5.3.3]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808) ~[spring-webmvc-5.3.3.jar!/:5.3.3]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.3.3.jar!/:5.3.3]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1060) ~[spring-webmvc-5.3.3.jar!/:5.3.3]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:962) ~[spring-webmvc-5.3.3.jar!/:5.3.3]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.3.3.jar!/:5.3.3]
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) ~[spring-webmvc-5.3.3.jar!/:5.3.3]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:626) ~[tomcat-embed-core-9.0.41.jar!/:4.0.FR]
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.3.3.jar!/:5.3.3]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:733) ~[tomcat-embed-core-9.0.41.jar!/:4.0.FR]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.3.3.jar!/:5.3.3]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.3.jar!/:5.3.3]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.3.3.jar!/:5.3.3]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.3.jar!/:5.3.3]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.3.3.jar!/:5.3.3]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.3.jar!/:5.3.3]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:888) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1597) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]
    at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]

これで、準備完了です。では、Fluentdの設定を行っていきましょう。

Parser Plugin / multilineで複数行のログファイルを読む

まずは、multilineを使うパターンです。

multiline - Fluentd

設定は、こんな感じで行いました。

/etc/td-agent/td-agent.conf

<source>
  @type tail
  @id app_log_tail

  <parse>
    @type multiline
    format_firstline /^\d{4}-\d\d-\d\d \d\d:\d\d:\d\d.\d{3}/
    format1 /^(?<log>(?<time>\d{4}-\d\d-\d\d \d\d:\d\d:\d\d.\d{3}).+)/
  </parse>

  path /tmp/spring.log
  pos_file /var/log/td-agent/app.log.pos
  tag app.log
</source>

<match app.**>
  @type stdout
  @id output_stdout
</match>

Tail Pluginで、ログファイルを読み続けます。この時に、Parser Pluginとしてmultilineを指定します。

  <parse>
    @type multiline
    format_firstline /^\d{4}-\d\d-\d\d \d\d:\d\d:\d\d.\d{3}/
    format1 /^(?<log>(?<time>\d{4}-\d\d-\d\d \d\d:\d\d:\d\d.\d{3}).+)/
  </parse>

アプリケーションログの日時の部分を開始行として定義しておきます。

また、timeをパターンとして指定していますが、time_keyのデフォルトはtimeらしいので、こちらに合わせておきました。

Config: Parse Section / Parse Parameters

それ以上のパースは今回は行いません。

出力先は、Stdout Plugin…つまり、Fluentd自身のログファイルにします。

<match app.**>
  @type stdout
  @id output_stdout
</match>

設定したら、Fluentdを再起動。

$ sudo systemctl restart td-agent

では、アプリケーションにアクセスしてみます。
※正確には、このあともう1回アクセスしないと最後のリクエストのログは書き出されませんが

$ curl localhost:8080/app/info
$ curl localhost:8080/app/error
$ curl localhost:8080/app/exception
$ curl localhost:8080/app/warn

Fluentdのログを見ます。

/var/log/td-agent/td-agent.log

2021-01-27 14:39:43.891000000 +0000 app.log: {"log":"2021-01-27 14:39:43.891  INFO 1263 --- [http-nio-8080-exec-5] org.littlewings.spring.example.App       : hello, info logging"}
2021-01-27 14:39:46.925000000 +0000 app.log: {"log":"2021-01-27 14:39:46.925 ERROR 1263 --- [http-nio-8080-exec-6] org.littlewings.spring.example.App       : oops!!, error logging"}
2021-01-27 14:40:14.398000000 +0000 app.log: {"log":"2021-01-27 14:40:14.398 ERROR 1263 --- [http-nio-8080-exec-7] org.littlewings.spring.example.App       : exception occurred, why?\n\njava.lang.RuntimeException: Oops!!\n\tat org.littlewings.spring.example.App.exception(App.java:44) ~[classes!/:na]\n\tat java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]\n\tat java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na]\n\tat java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]\n\tat java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[na:na]\n\tat org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:894) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1060) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:962) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:626) ~[tomcat-embed-core-9.0.41.jar!/:4.0.FR]\n\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:733) ~[tomcat-embed-core-9.0.41.jar!/:4.0.FR]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:888) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1597) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]\n\tat org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]\n"}
2021-01-27 14:40:20.487000000 +0000 app.log: {"log":"2021-01-27 14:40:20.487  WARN 1263 --- [http-nio-8080-exec-8] org.littlewings.spring.example.App       : world, warn logging"}

スタックトレースもまとまった行になっていることがわかりますね。

ちなみに、time_keyで指定されているフィールド（今回はデフォルトのtime）を残すには、keep_time_keyをtrueに
設定します。

  <parse>
    @type multiline
    format_firstline /^\d{4}-\d\d-\d\d \d\d:\d\d:\d\d.\d{3}/
    format1 /^(?<log>(?<time>\d{4}-\d\d-\d\d \d\d:\d\d:\d\d.\d{3}).+)/

    keep_time_key true
  </parse>

確認。

2021-01-27 14:45:26.306000000 +0000 app.log: {"log":"2021-01-27 14:45:26.306  INFO 1263 --- [http-nio-8080-exec-10] org.littlewings.spring.example.App       : hello, info logging","time":"2021-01-27 14:45:26.306"}

fluent-plugin-concat

次は、fluent-plugin-concatを使います。

GitHub - fluent-plugins-nursery/fluent-plugin-concat: Fluentd Filter plugin to concatenate multiline log separated in multiple events.

こちらはサードパーティ製のプラグインになるので、インストールが必要です。こちらのドキュメントに記載されている
プラグインのインストールコマンドを確認したら

Plugin Management - Fluentd

インストールします。

$ sudo td-agent-gem install fluent-plugin-concat
Fetching fluent-plugin-concat-2.4.0.gem
Successfully installed fluent-plugin-concat-2.4.0
Parsing documentation for fluent-plugin-concat-2.4.0
Installing ri documentation for fluent-plugin-concat-2.4.0
Done installing documentation for fluent-plugin-concat after 0 seconds
1 gem installed

今回は2.4.0がインストールされました。

インストールされた場所は、こちら。

$ ll /opt/td-agent/lib/ruby/gems/2.7.0/gems/fluent-plugin-concat-2.4.0
total 56
drwxr-xr-x   4 root root 4096 Jan 25 15:13 ./
drwxr-xr-x 131 root root 4096 Jan 25 15:13 ../
-rw-r--r--   1 root root    0 Jan 25 15:13 Appraisals
-rw-r--r--   1 root root 1047 Jan 25 15:13 fluent-plugin-concat.gemspec
-rw-r--r--   1 root root  105 Jan 25 15:13 Gemfile
drwxr-xr-x   2 root root 4096 Jan 25 15:13 .github/
-rw-r--r--   1 root root   53 Jan 25 15:13 .gitignore
drwxr-xr-x   3 root root 4096 Jan 25 15:13 lib/
-rw-r--r--   1 root root 1072 Jan 25 15:13 LICENSE.txt
-rw-r--r--   1 root root  762 Jan 25 15:13 NEWS.md
-rw-r--r--   1 root root  219 Jan 25 15:13 Rakefile
-rw-r--r--   1 root root 4718 Jan 25 15:13 README.md
-rw-r--r--   1 root root 1153 Jan 25 15:13 .rubocop.yml
-rw-r--r--   1 root root  970 Jan 25 15:13 .travis.yml

では、設定します。

/etc/td-agent/td-agent.conf

<source>
  @type tail
  @id app_log_tail

  <parse>
    @type regexp
    expression /(?<log>.*)/
  </parse>


  path /tmp/spring.log
  pos_file /var/log/td-agent/app.log.pos
  tag app.log
</source>

<filter app.**>
  @type concat
  key log
  multiline_start_regexp /^\d{4}-\d\d-\d\d \d\d:\d\d:\d\d.\d{3}/
</filter>

<filter app.**>
  @type parser
  key_name log

  <parse>
    @type regexp
    expression /^(?<log>(?<time>\d{4}-\d\d-\d\d \d\d:\d\d:\d\d.\d{3}).+)/m

    keep_time_key true
  </parse>
</filter>


<match app.**>
  @type stdout
  @id output_stdout
</match>

複数行のログファイルはfluent-plugin-concatで結合させるので、Tail Pluginはなにも考えずに1行ずつログレコードとして
読み取るように設定します。

<source>
  @type tail
  @id app_log_tail

  <parse>
    @type regexp
    expression /(?<log>.*)/
  </parse>


  path /tmp/spring.log
  pos_file /var/log/td-agent/app.log.pos
  tag app.log
</source>

Tail Pluginで読み取ったログは、fluent-plugin-concatで結合させます。先ほどのmultilineの時と同様に、日時のパターンを
ログの開始パターンとして定義しました。

<filter app.**>
  @type concat
  key log
  multiline_start_regexp /^\d{4}-\d\d-\d\d \d\d:\d\d:\d\d.\d{3}/
</filter>

あとはオマケで、time_key（timeフィールド）を抜き出すために、regex Parser Pluginを付けています。
今回は最初からkeep_time_keyはtrueにしています。

<filter app.**>
  @type parser
  key_name log

  <parse>
    @type regexp
    expression /^(?<log>(?<time>\d{4}-\d\d-\d\d \d\d:\d\d:\d\d.\d{3}).+)/m

    keep_time_key true
  </parse>
</filter>

設定したら、Fluentdを再起動して

$ sudo systemctl restart td-agent

アプリケーションにアクセスしてみます。
※やっぱり、このあとにもう1回リクエストをつけています

$ curl localhost:8080/app/info
$ curl localhost:8080/app/error
$ curl localhost:8080/app/exception
$ curl localhost:8080/app/warn

Fluentdのログを確認。

/var/log/td-agent/td-agent.log

2021-01-27 14:59:28.464000000 +0000 app.log: {"log":"2021-01-27 14:59:28.464  INFO 1263 --- [http-nio-8080-exec-4] org.littlewings.spring.example.App       : hello, info logging","time":"2021-01-27 14:59:28.464"}
2021-01-27 14:59:30.036000000 +0000 app.log: {"log":"2021-01-27 14:59:30.036 ERROR 1263 --- [http-nio-8080-exec-2] org.littlewings.spring.example.App       : oops!!, error logging","time":"2021-01-27 14:59:30.036"}
2021-01-27 14:59:34.503000000 +0000 app.log: {"log":"2021-01-27 14:59:34.503 ERROR 1263 --- [http-nio-8080-exec-6] org.littlewings.spring.example.App       : exception occurred, why?\n\njava.lang.RuntimeException: Oops!!\n\tat org.littlewings.spring.example.App.exception(App.java:44) ~[classes!/:na]\n\tat java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]\n\tat java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:na]\n\tat java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]\n\tat java.base/java.lang.reflect.Method.invoke(Method.java:566) ~[na:na]\n\tat org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:894) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1060) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:962) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:626) ~[tomcat-embed-core-9.0.41.jar!/:4.0.FR]\n\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.3.3.jar!/:5.3.3]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:733) ~[tomcat-embed-core-9.0.41.jar!/:4.0.FR]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.3.3.jar!/:5.3.3]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:374) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:888) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1597) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]\n\tat java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]\n\tat org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.41.jar!/:9.0.41]\n\tat java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]\n","time":"2021-01-27 14:59:34.503"}
2021-01-27 14:59:36.987000000 +0000 app.log: {"log":"2021-01-27 14:59:36.987  WARN 1263 --- [http-nio-8080-exec-7] org.littlewings.spring.example.App       : world, warn logging","time":"2021-01-27 14:59:36.987"}

スタックトレースを含んだログも結合されていますし、OKですね。

まとめ

Fluentdを使って、複数行のログを読む方法を2つ試してみました。

multilineの設定って、1回試した後に時間が空くとすぐ忘れてしまうのですが…こうやってメモしておくのが良いのでしょう…。

きっと、また思い出すために見ることになるでしょう。