これは、なにをしたくて書いたもの？
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
こんな感じで。
$ 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の使用例は、こちらを見るとよいと思います。
