CLOVER🍀

That was when it all began.

Filebeatで、複数行のログをElasticsearchに取り込んでみる

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

Filebeatで、複数行で書かれたログを読む時の設定、挙動を確認してみようかなと思いまして。

環境

今回の環境は、こちら。

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 18.04.3 LTS
Release:    18.04
Codename:   bionic


$ java --version
openjdk 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)

FilebeatもElasticsearchも、7.5.0です。

$ filebeat version
filebeat version 7.5.0 (amd64), libbeat 7.5.0 [6d0d0ae079e5cb1d4f224801ac6df926dfb1594c built 2019-11-26 00:06:12 +0000 UTC]


$ curl localhost:9200
{
  "name" : "ubuntu1804.localdomain",
  "cluster_name" : "elasticsearch",
  "cluster_uuid" : "b2DoYDyVTkOd2tNwLI1Y0A",
  "version" : {
    "number" : "7.5.0",
    "build_flavor" : "default",
    "build_type" : "deb",
    "build_hash" : "e9ccaed468e2fac2275a3761849cbee64b39519f",
    "build_date" : "2019-11-26T01:06:52.518245Z",
    "build_snapshot" : false,
    "lucene_version" : "8.3.0",
    "minimum_wire_compatibility_version" : "6.8.0",
    "minimum_index_compatibility_version" : "6.0.0-beta1"
  },
  "tagline" : "You Know, for Search"
}

FilebeatでMultiline Messageを読む

FilebeatでのMultiline Message(複数行のメッセージ)に関するドキュメントは、こちら。

Manage multiline messages | Filebeat Reference [7.5] | Elastic

Examples of multiline configuration | Filebeat Reference [7.5] | Elastic

身近な例では、以下のようなJavaのスタックトレースをひとまとまりのログとして扱うケースです。

[beat-logstash-some-name-832-2015.11.28] IndexNotFoundException[no such index]
    at org.elasticsearch.cluster.metadata.IndexNameExpressionResolver$WildcardExpressionResolver.resolve(IndexNameExpressionResolver.java:566)
    at org.elasticsearch.cluster.metadata.IndexNameExpressionResolver.concreteIndices(IndexNameExpressionResolver.java:133)
    at org.elasticsearch.cluster.metadata.IndexNameExpressionResolver.concreteIndices(IndexNameExpressionResolver.java:77)
    at org.elasticsearch.action.admin.indices.delete.TransportDeleteIndexAction.checkBlock(TransportDeleteIndexAction.java:75)

設定は、以下の6つがあります。

  • multiline.pattern … 複数行を判定に使う正規表現パターン(Regular expression support | Filebeat Reference [7.5] | Elastic)
  • multiline.negate … パターンを無効にするか(デフォルトfalseで、enabledとはまた違う)
  • multiline.match … 複数行扱いされたデータを、前後のデータのどちらにくっつけるか(before、afterで指定)
  • multiline.flush_pattern … 複数行の終わりを表す正規表現
  • multiline.max_lines … ひとつのデータとして扱う最大行数。これを超えた行は破棄される(デフォルト500)
  • multiline.timeout … 複数行が終了しない場合の待ち時間。これを超えると、データとして完結して送信される(デフォルト5秒)

基本で使うのは、pattern、nagate、matchなのですが、説明を見ても意味がよくわからないので(図もあるのですが…)実際に試して
みたいと思います。

ログ出力を行う簡単なSpring Bootアプリケーションを作り、こちらのログを取り込んでみたいと思います。

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

Maven依存関係や、設定はこちら。

    <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.2.2.RELEASE</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.2.2.RELEASE</version>
                <executions>
                  <execution>
                    <goals>
                      <goal>repackage</goal>
                    </goals>
                  </execution>
                </executions>
            </plugin>
        </plugins>
    </build>

アクセスされたらログを出力するだけの、簡単な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

Spring Bootのログまわりのドキュメント、設定を見つつ実行します。

Spring Boot Features / Logging

Common Application properties / Core properties

https://github.com/spring-projects/spring-boot/blob/v2.2.2.RELEASE/spring-boot-project/spring-boot/src/main/java/org/springframework/boot/logging/logback/DefaultLogbackConfiguration.java

https://github.com/spring-projects/spring-boot/tree/v2.2.2.RELEASE/spring-boot-project/spring-boot/src/main/resources/org/springframework/boot/logging/logback

こんな感じで。

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

これで、「/tmp/spring.log」というファイルにログが出力されます。

$ cat /tmp/spring.log 
2019-12-07 05:59:19.155  INFO 6289 --- [main] org.littlewings.spring.example.App       : Starting App on ubuntu1804.localdomain with PID 6289 (/home/vagrant/simple-logging-web-app.jar started by vagrant in /home/vagrant)
2019-12-07 05:59:19.161  INFO 6289 --- [main] org.littlewings.spring.example.App       : No active profile set, falling back to default profiles: default
2019-12-07 05:59:20.565  INFO 6289 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2019-12-07 05:59:20.576  INFO 6289 --- [main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2019-12-07 05:59:20.576  INFO 6289 --- [main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.29]
2019-12-07 05:59:20.647  INFO 6289 --- [main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2019-12-07 05:59:20.647  INFO 6289 --- [main] o.s.web.context.ContextLoader            : Root WebApplicationContext: initialization completed in 1389 ms
2019-12-07 05:59:20.867  INFO 6289 --- [main] o.s.s.concurrent.ThreadPoolTaskExecutor  : Initializing ExecutorService 'applicationTaskExecutor'
2019-12-07 05:59:21.118  INFO 6289 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2019-12-07 05:59:21.128  INFO 6289 --- [main] org.littlewings.spring.example.App       : Started App in 2.841 seconds (JVM running for 3.312)

ログ出力確認。

$ curl localhost:8080/app/info
info logging

$ curl localhost:8080/app/error
error logging

$ curl localhost:8080/app/exception
exception logging

こんな感じになります。

2019-12-07 06:00:47.170  INFO 6289 --- [http-nio-8080-exec-1] org.littlewings.spring.example.App       : hello, info logging
2019-12-07 06:00:54.423 ERROR 6289 --- [http-nio-8080-exec-2] org.littlewings.spring.example.App       : oops!!, error logging
2019-12-07 06:00:57.668 ERROR 6289 --- [http-nio-8080-exec-4] 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:190) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:888) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:634) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:741) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:526) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:367) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1591) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]
    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.29.jar!/:9.0.29]
    at java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]

Filebeatを設定する

では、Filebeatの設定をしていきます。

最初は、こんな感じです。

$ sudo grep -vE ' *#|^$' /etc/filebeat/filebeat.yml 
filebeat.inputs:
- type: log
  enabled: false
  paths:
    - /var/log/*.log
filebeat.config.modules:
  path: ${path.config}/modules.d/*.yml
  reload.enabled: false
setup.template.settings:
  index.number_of_shards: 1
output.elasticsearch:
  hosts: ["localhost.12:9200"]
processors:
  - add_host_metadata: ~
  - add_cloud_metadata: ~
  - add_docker_metadata: ~
  - add_kubernetes_metadata: ~

ここで、inputの部分をこのように修正して(この時点では、Multilineのことは考えません)

filebeat.inputs:
- type: log
  enabled: true
  paths:
    - /tmp/spring.log

Filebeatを再起動。

$ sudo systemctl restart filebeat

起動時に現時点のログファイルを読み込むので、Elasticsearchで1度確認。

$ curl localhost:9200/filebeat-7.5.0-2019.12.07-000001/_search?pretty

こんな感じで、ログが入っていました。

{
  "took" : 0,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 10,
      "relation" : "eq"
    },
    "max_score" : 1.0,
    "hits" : [
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "qomr4G4BuCfTKvwhKngO",
        "_score" : 1.0,
        "_source" : {
          "@timestamp" : "2019-12-07T14:02:21.714Z",
          "log" : {
            "offset" : 0,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          },
          "message" : "2019-12-07 06:02:13.356  INFO 6392 --- [main] org.littlewings.spring.example.App       : Starting App on ubuntu1804.localdomain with PID 6392 (/home/vagrant/simple-logging-web-app.jar started by vagrant in /home/vagrant)",
          "input" : {
            "type" : "log"
          },
          "ecs" : {
            "version" : "1.1.0"
          },
          "host" : {
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain",
            "architecture" : "x86_64",
            "name" : "ubuntu1804.localdomain",
            "os" : {
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian",
              "name" : "Ubuntu",
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic"
            },
            "id" : "7c755c59fed6434da78eedb3429e95f4"
          },
          "agent" : {
            "type" : "filebeat",
            "ephemeral_id" : "462f1502-d9b3-4b3b-a1c6-3fa6f655d220",
            "hostname" : "ubuntu1804.localdomain",
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f",
            "version" : "7.5.0"
          }
        }
      },
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "q4mr4G4BuCfTKvwhKngO",
        "_score" : 1.0,
        "_source" : {
          "@timestamp" : "2019-12-07T14:02:21.714Z",
          "ecs" : {
            "version" : "1.1.0"
          },
          "log" : {
            "offset" : 221,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          },
          "message" : "2019-12-07 06:02:13.367  INFO 6392 --- [main] org.littlewings.spring.example.App       : No active profile set, falling back to default profiles: default",
          "input" : {
            "type" : "log"
          },
          "host" : {
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain",
            "name" : "ubuntu1804.localdomain",
            "architecture" : "x86_64",
            "os" : {
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic",
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian",
              "name" : "Ubuntu"
            }
          },
          "agent" : {
            "type" : "filebeat",
            "ephemeral_id" : "462f1502-d9b3-4b3b-a1c6-3fa6f655d220",
            "hostname" : "ubuntu1804.localdomain",
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f",
            "version" : "7.5.0"
          }
        }
      },
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "rImr4G4BuCfTKvwhKngO",
        "_score" : 1.0,
        "_source" : {
          "@timestamp" : "2019-12-07T14:02:21.714Z",
          "agent" : {
            "type" : "filebeat",
            "ephemeral_id" : "462f1502-d9b3-4b3b-a1c6-3fa6f655d220",
            "hostname" : "ubuntu1804.localdomain",
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f",
            "version" : "7.5.0"
          },
          "ecs" : {
            "version" : "1.1.0"
          },
          "host" : {
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "containerized" : false,
            "name" : "ubuntu1804.localdomain",
            "hostname" : "ubuntu1804.localdomain",
            "architecture" : "x86_64",
            "os" : {
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic",
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian",
              "name" : "Ubuntu"
            }
          },
          "message" : "2019-12-07 06:02:14.458  INFO 6392 --- [main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)",
          "log" : {
            "offset" : 375,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          },
          "input" : {
            "type" : "log"
          }
        }
      }
    ]
  }
}

では、まずはINFOログを出力させて見ると

$ curl localhost:8080/app/info
info logging

少し待つと、Elasticsearchのログが入ったのが確認できます。

{
  "took" : 0,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 14,
      "relation" : "eq"
    },
    "max_score" : null,
    "hits" : [
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "t4mv4G4BuCfTKvwh33h5",
        "_score" : null,
        "_source" : {
          "@timestamp" : "2019-12-07T14:07:31.726Z",
          "agent" : {
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f",
            "version" : "7.5.0",
            "type" : "filebeat",
            "ephemeral_id" : "462f1502-d9b3-4b3b-a1c6-3fa6f655d220",
            "hostname" : "ubuntu1804.localdomain"
          },
          "log" : {
            "offset" : 1936,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          },
          "message" : "2019-12-07 06:07:31.667  INFO 6392 --- [http-nio-8080-exec-1] org.littlewings.spring.example.App       : hello, info logging",
          "input" : {
            "type" : "log"
          },
          "ecs" : {
            "version" : "1.1.0"
          },
          "host" : {
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain",
            "architecture" : "x86_64",
            "name" : "ubuntu1804.localdomain",
            "os" : {
              "family" : "debian",
              "name" : "Ubuntu",
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic",
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)"
            }
          }
        },
        "sort" : [
          1936
        ]
      }
    ]
  }
}

では、次にスタックトレースを伴うようなログ出力をしてみます。

$ curl localhost:8080/app/exception
exception logging

確認。

$ curl -XPOST -H 'Content-Type: application/json' 'localhost:9200/filebeat-7.5.0-2019.12.07-000001/_search?pretty&size=54' -d '{"sort": [{"log.offset": "desc"}]}'

最初の1行はまだいいのですが

      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "uImz4G4BuCfTKvwhnHiO",
        "_score" : null,
        "_source" : {
          "@timestamp" : "2019-12-07T14:11:36.736Z",
          "agent" : {
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f",
            "version" : "7.5.0",
            "type" : "filebeat",
            "ephemeral_id" : "462f1502-d9b3-4b3b-a1c6-3fa6f655d220",
            "hostname" : "ubuntu1804.localdomain"
          },
          "log" : {
            "file" : {
              "path" : "/tmp/spring.log"
            },
            "offset" : 2061
          },
          "message" : "2019-12-07 06:11:34.235 ERROR 6392 --- [http-nio-8080-exec-2] org.littlewings.spring.example.App       : exception occurred, why?",
          "input" : {
            "type" : "log"
          },
          "ecs" : {
            "version" : "1.1.0"
          },
          "host" : {
            "name" : "ubuntu1804.localdomain",
            "architecture" : "x86_64",
            "os" : {
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic",
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian",
              "name" : "Ubuntu"
            },
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain"
          }
        },
        "sort" : [
          2061
        ]
      },

スタックトレースは行単位にバラバラに取り込まれます。

      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "uYmz4G4BuCfTKvwhnHiO",
        "_score" : null,
        "_source" : {
          "@timestamp" : "2019-12-07T14:11:36.736Z",
          "log" : {
            "offset" : 2192,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          },
          "message" : "java.lang.RuntimeException: Oops!!",
          "input" : {
            "type" : "log"
          },
          "host" : {
            "architecture" : "x86_64",
            "os" : {
              "name" : "Ubuntu",
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic",
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian"
            },
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "name" : "ubuntu1804.localdomain",
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain"
          },
          "agent" : {
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f",
            "version" : "7.5.0",
            "type" : "filebeat",
            "ephemeral_id" : "462f1502-d9b3-4b3b-a1c6-3fa6f655d220",
            "hostname" : "ubuntu1804.localdomain"
          },
          "ecs" : {
            "version" : "1.1.0"
          }
        },
        "sort" : [
          2192
        ]
      },
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "v4mz4G4BuCfTKvwhnHiO",
        "_score" : null,
        "_source" : {
          "@timestamp" : "2019-12-07T14:11:36.736Z",
          "agent" : {
            "hostname" : "ubuntu1804.localdomain",
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f",
            "version" : "7.5.0",
            "type" : "filebeat",
            "ephemeral_id" : "462f1502-d9b3-4b3b-a1c6-3fa6f655d220"
          },
          "log" : {
            "offset" : 2697,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          },
          "message" : "\tat org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:190) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]",
          "input" : {
            "type" : "log"
          },
          "ecs" : {
            "version" : "1.1.0"
          },
          "host" : {
            "name" : "ubuntu1804.localdomain",
            "architecture" : "x86_64",
            "os" : {
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian",
              "name" : "Ubuntu",
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic"
            },
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain"
          }
        },
        "sort" : [
          2697
        ]
      },

これでは嬉しくないですね。では、Multilineの設定をしていきましょう。

とりあえず、Elasticsearchのインデックスを1度削除。

$ curl -XDELETE localhost:9200/filebeat-7.5.0-2019.12.07-000001
{"acknowledged":true}

Multilineの設定を追加します。

filebeat.inputs:
- type: log
  enabled: true
  paths:
    - /tmp/spring.log

  multiline.pattern: '^[[:space:]]'
  multiline.negate: false
  multiline.match: after

multiline.patternで使える正規表現は、Logstashのものとは違うようなので注意が必要です。

Regular expression support | Filebeat Reference [7.5] | Elastic

さて、この設定の意味なのですが

  multiline.pattern: '^[[:space:]]'
  multiline.negate: false
  multiline.match: after

ホワイトスペース(multiline.pattern)で始まっているものにマッチする連続した行(multiline.nagate: false)が、直前のマッチしない行の後ろ
(multiline.match: before)に追加される、です。

この状態でFilebeatを再起動して、以下のようにリクエストを送ると

$ curl localhost:8080/app/info
info logging

$ curl localhost:8080/app/exception
exception logging

$ curl localhost:8080/app/warn
warn logging

こんな感じになります。

$ curl -XPOST -H 'Content-Type: application/json' 'localhost:9200/filebeat-7.5.0-2019.12.07-000001/_search?pretty' -d '{"sort": [{"log.offset": "desc"}]}'
{
  "took" : 0,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 4,
      "relation" : "eq"
    },
    "max_score" : null,
    "hits" : [
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "8Im54G4BuCfTKvwh-niH",
        "_score" : null,
        "_source" : {
          "@timestamp" : "2019-12-07T14:18:29.012Z",
          "ecs" : {
            "version" : "1.1.0"
          },
          "log" : {
            "offset" : 16072,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          },
          "message" : "2019-12-07 06:18:27.552  WARN 6392 --- [http-nio-8080-exec-6] org.littlewings.spring.example.App       : world, warn logging",
          "input" : {
            "type" : "log"
          },
          "host" : {
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain",
            "architecture" : "x86_64",
            "os" : {
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian",
              "name" : "Ubuntu",
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic",
              "platform" : "ubuntu"
            },
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "name" : "ubuntu1804.localdomain"
          },
          "agent" : {
            "hostname" : "ubuntu1804.localdomain",
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f",
            "version" : "7.5.0",
            "type" : "filebeat",
            "ephemeral_id" : "bc247b47-3d3a-4fde-86c9-717abf55847a"
          }
        },
        "sort" : [
          16072
        ]
      },
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "74m54G4BuCfTKvwhE3iT",
        "_score" : null,
        "_source" : {
          "@timestamp" : "2019-12-07T14:17:34.008Z",
          "message" : "java.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:190) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:888) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:634) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:741) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:526) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:367) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1591) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\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.29.jar!/:9.0.29]\n\tat java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]",
          "log" : {
            "offset" : 9260,
            "file" : {
              "path" : "/tmp/spring.log"
            },
            "flags" : [
              "multiline"
            ]
          },
          "input" : {
            "type" : "log"
          },
          "ecs" : {
            "version" : "1.1.0"
          },
          "host" : {
            "name" : "ubuntu1804.localdomain",
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain",
            "architecture" : "x86_64",
            "os" : {
              "family" : "debian",
              "name" : "Ubuntu",
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic",
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)"
            }
          },
          "agent" : {
            "version" : "7.5.0",
            "type" : "filebeat",
            "ephemeral_id" : "bc247b47-3d3a-4fde-86c9-717abf55847a",
            "hostname" : "ubuntu1804.localdomain",
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f"
          }
        },
        "sort" : [
          9260
        ]
      },
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "7om54G4BuCfTKvwhE3iT",
        "_score" : null,
        "_source" : {
          "@timestamp" : "2019-12-07T14:17:34.008Z",
          "log" : {
            "offset" : 9129,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          },
          "message" : "2019-12-07 06:17:31.684 ERROR 6392 --- [http-nio-8080-exec-5] org.littlewings.spring.example.App       : exception occurred, why?",
          "input" : {
            "type" : "log"
          },
          "host" : {
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain",
            "architecture" : "x86_64",
            "os" : {
              "codename" : "bionic",
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian",
              "name" : "Ubuntu",
              "kernel" : "4.15.0-70-generic"
            },
            "name" : "ubuntu1804.localdomain",
            "id" : "7c755c59fed6434da78eedb3429e95f4"
          },
          "agent" : {
            "type" : "filebeat",
            "ephemeral_id" : "bc247b47-3d3a-4fde-86c9-717abf55847a",
            "hostname" : "ubuntu1804.localdomain",
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f",
            "version" : "7.5.0"
          },
          "ecs" : {
            "version" : "1.1.0"
          }
        },
        "sort" : [
          9129
        ]
      },
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "7Ym54G4BuCfTKvwhE3iS",
        "_score" : null,
        "_source" : {
          "@timestamp" : "2019-12-07T14:17:34.008Z",
          "input" : {
            "type" : "log"
          },
          "ecs" : {
            "version" : "1.1.0"
          },
          "host" : {
            "name" : "ubuntu1804.localdomain",
            "hostname" : "ubuntu1804.localdomain",
            "architecture" : "x86_64",
            "os" : {
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic",
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian",
              "name" : "Ubuntu"
            },
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "containerized" : false
          },
          "agent" : {
            "version" : "7.5.0",
            "type" : "filebeat",
            "ephemeral_id" : "bc247b47-3d3a-4fde-86c9-717abf55847a",
            "hostname" : "ubuntu1804.localdomain",
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f"
          },
          "log" : {
            "offset" : 9004,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          },
          "message" : "2019-12-07 06:17:25.905  INFO 6392 --- [http-nio-8080-exec-3] org.littlewings.spring.example.App       : hello, info logging"
        },
        "sort" : [
          9004
        ]
      }
    ]
  }
}

スタックトレースがまとまりましたね。

ところで、よくよく見るとスタックトレースと、ERRORレベルで出力したログが別々になってしまっています。

          "message" : "java.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:190) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:888) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:634) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:741) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:526) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:367) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1591) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\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.29.jar!/:9.0.29]\n\tat java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]",


          "message" : "2019-12-07 06:17:31.684 ERROR 6392 --- [http-nio-8080-exec-5] org.littlewings.spring.example.App       : exception occurred, why?",

ここで、ERRORログ+スタックトレースをもう1度見てみます。

2019-12-07 06:17:31.684 ERROR 6392 --- [http-nio-8080-exec-5] 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]

設定を見ます。

  multiline.pattern: '^[[:space:]]'
  multiline.negate: false
  multiline.match: after

今回の設定だと、ホワイトスペースで始まっている連続した行が、パターンにマッチしない直前の行の後ろにくっつく、なので、
スタックトレースがここにまとまってしまうわけですね。

java.lang.RuntimeException: Oops!!

もう1度、インデックスを削除。

$ curl -XDELETE localhost:9200/filebeat-7.5.0-2019.12.07-000001
{"acknowledged":true}

今度は、こんな設定にしてみます。

filebeat.inputs:
- type: log
  enabled: true
  paths:
    - /tmp/spring.log

  multiline.pattern: '^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}\.\d{3}'
  multiline.negate: true
  multiline.match: after

これは、^\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}に(multiline.pattern)マッチしない連続した行(multiline.negate: true)が、直前のマッチする行の
後にくっつく(multiline.match: after)、です。

Filebeatを再起動して、確認してみましょう。

$ curl localhost:8080/app/info
info logging

$ curl localhost:8080/app/exception
exception logging

$ curl localhost:8080/app/warn
warn logging

結果。

$ curl -XPOST -H 'Content-Type: application/json' 'localhost:9200/filebeat-7.5.0-2019.12.07-000001/_search?pretty' -d '{"sort": [{"log.offset": "desc"}]}'
{
  "took" : 1,
  "timed_out" : false,
  "_shards" : {
    "total" : 1,
    "successful" : 1,
    "skipped" : 0,
    "failed" : 0
  },
  "hits" : {
    "total" : {
      "value" : 3,
      "relation" : "eq"
    },
    "max_score" : null,
    "hits" : [
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "84m-4G4BuCfTKvwhGnhg",
        "_score" : null,
        "_source" : {
          "@timestamp" : "2019-12-07T14:22:59.312Z",
          "ecs" : {
            "version" : "1.1.0"
          },
          "host" : {
            "os" : {
              "name" : "Ubuntu",
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic",
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian"
            },
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain",
            "name" : "ubuntu1804.localdomain",
            "architecture" : "x86_64"
          },
          "log" : {
            "offset" : 23266,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          },
          "message" : "2019-12-07 06:22:51.868  WARN 6392 --- [http-nio-8080-exec-2] org.littlewings.spring.example.App       : world, warn logging",
          "input" : {
            "type" : "log"
          },
          "agent" : {
            "type" : "filebeat",
            "ephemeral_id" : "e5ba7545-ce3a-458b-97ae-0500c567f60d",
            "hostname" : "ubuntu1804.localdomain",
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f",
            "version" : "7.5.0"
          }
        },
        "sort" : [
          23266
        ]
      },
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "8om94G4BuCfTKvwh33jI",
        "_score" : null,
        "_source" : {
          "@timestamp" : "2019-12-07T14:22:44.310Z",
          "input" : {
            "type" : "log"
          },
          "ecs" : {
            "version" : "1.1.0"
          },
          "host" : {
            "os" : {
              "codename" : "bionic",
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian",
              "name" : "Ubuntu",
              "kernel" : "4.15.0-70-generic"
            },
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain",
            "architecture" : "x86_64",
            "name" : "ubuntu1804.localdomain"
          },
          "agent" : {
            "version" : "7.5.0",
            "type" : "filebeat",
            "ephemeral_id" : "e5ba7545-ce3a-458b-97ae-0500c567f60d",
            "hostname" : "ubuntu1804.localdomain",
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f"
          },
          "log" : {
            "flags" : [
              "multiline"
            ],
            "offset" : 16322,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          },
          "message" : "2019-12-07 06:22:43.727 ERROR 6392 --- [http-nio-8080-exec-10] 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:190) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:888) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:634) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:741) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:526) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:367) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1591) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\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.29.jar!/:9.0.29]\n\tat java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]\n"
        },
        "sort" : [
          16322
        ]
      },
      {
        "_index" : "filebeat-7.5.0-2019.12.07-000001",
        "_type" : "_doc",
        "_id" : "8Ym94G4BuCfTKvwh0Hhn",
        "_score" : null,
        "_source" : {
          "@timestamp" : "2019-12-07T14:22:43.310Z",
          "message" : "2019-12-07 06:22:33.370  INFO 6392 --- [http-nio-8080-exec-8] org.littlewings.spring.example.App       : hello, info logging",
          "input" : {
            "type" : "log"
          },
          "agent" : {
            "version" : "7.5.0",
            "type" : "filebeat",
            "ephemeral_id" : "e5ba7545-ce3a-458b-97ae-0500c567f60d",
            "hostname" : "ubuntu1804.localdomain",
            "id" : "bdc4cda9-f501-49fc-b8d9-0476b505d59f"
          },
          "ecs" : {
            "version" : "1.1.0"
          },
          "host" : {
            "name" : "ubuntu1804.localdomain",
            "os" : {
              "name" : "Ubuntu",
              "kernel" : "4.15.0-70-generic",
              "codename" : "bionic",
              "platform" : "ubuntu",
              "version" : "18.04.3 LTS (Bionic Beaver)",
              "family" : "debian"
            },
            "id" : "7c755c59fed6434da78eedb3429e95f4",
            "containerized" : false,
            "hostname" : "ubuntu1804.localdomain",
            "architecture" : "x86_64"
          },
          "log" : {
            "offset" : 16197,
            "file" : {
              "path" : "/tmp/spring.log"
            }
          }
        },
        "sort" : [
          16197
        ]
      }
    ]
  }
}

今回のパターン定義と設定の組み合わせだと、ERRORログとスタックトレースが同じデータとして扱われるようになりましたね。

ちなみに、この設定で「multiline.match」を「before」にするとスタックトレースのERRORログ部分が独立して

          "message" : "2019-12-07 08:09:17.128 ERROR 6392 --- [http-nio-8080-exec-6] org.littlewings.spring.example.App       : exception occurred, why?",

スタックトレースの方は、WARNログの方にくっつきます。

          "message" : "java.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:190) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:138) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:888) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:793) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:634) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat javax.servlet.http.HttpServlet.service(HttpServlet.java:741) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:231) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119) ~[spring-web-5.2.2.RELEASE.jar!/:5.2.2.RELEASE]\n\tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:193) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:166) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:526) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:367) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:860) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1591) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\n\tat org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.29.jar!/:9.0.29]\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.29.jar!/:9.0.29]\n\tat java.base/java.lang.Thread.run(Thread.java:834) ~[na:na]\n\n2019-12-07 08:09:18.076  WARN 6392 --- [http-nio-8080-exec-7] org.littlewings.spring.example.App       : world, warn logging",

つまり?

とまあ、ここまでをまとめると

  • multiline.negate: falseの場合、multiline.patternにマッチする連続した行が
    • 直前のマッチしなかった行の後に結合される(multiline.match: after)
    • 直後のマッチしなかった行の前に結合される(multiline.match: before)
  • multiline.negate: trueの場合、multiline.patternにマッチしなかった連続した行が
    • 直前のマッチする行の後に結合される(multiline.match: after)
    • 直後のマッチする行の前に結合される(multiline.match: before)

となります。

ああ、わかりにくい。

とりあえず、挙動は把握できた感じなので、OKとしましょう。

今回触れなかったmultiline.flush_patternの使用例は、こちらを見るとよいと思います。

Examples of multiline configuration / Application events