fluent / fluent-bit

Fast and Lightweight Logs and Metrics processor for Linux, BSD, OSX and Windows
https://fluentbit.io
Apache License 2.0
5.74k stars 1.56k forks source link

java multiline filter parse error #5812

Closed shalousun closed 1 year ago

shalousun commented 2 years ago

Bug Report

Describe the bug Handling java exception log errors using multiline filter,A complete exception log is split into two,The configuration is as follows

[FILTER]
        Name                  multiline
        Match                 kube.*
        multiline.key_content log
        multiline.parser      java

after filter, first logs content is

2022-07-31 23:41:34.668 [http-nio-8080-exec-10] ERROR com.benchmark.springboot.error.RestExceptionHandler@unknownException:77 - Error code 500:{}

second log content

java.lang.ArithmeticException: / by zero
    at com.benchmark.springboot.controller.ExceptionTestController.testException(ExceptionTestController.java:22) ~[classes!/:1.0-SNAPSHOT]
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
    at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) ~[spring-web-5.3.18.jar!/:5.3.18]
    at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150) ~[spring-web-5.3.18.jar!/:5.3.18]
    at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117) ~[spring-webmvc-5.3.18.jar!/:5.3.18]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:895) ~[spring-webmvc-5.3.18.jar!/:5.3.18]
    at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808) ~[spring-webmvc-5.3.18.jar!/:5.3.18]
    at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.3.18.jar!/:5.3.18]
    at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1067) [spring-webmvc-5.3.18.jar!/:5.3.18]
    at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:963) [spring-webmvc-5.3.18.jar!/:5.3.18]
    at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) [spring-webmvc-5.3.18.jar!/:5.3.18]
    at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898) [spring-webmvc-5.3.18.jar!/:5.3.18]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:655) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) [spring-webmvc-5.3.18.jar!/:5.3.18]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) [tomcat-embed-websocket-9.0.60.jar!/:?]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:96) [spring-boot-actuator-2.6.6.jar!/:2.6.6]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.18.jar!/:5.3.18]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) [spring-web-5.3.18.jar!/:5.3.18]
    at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) [spring-web-5.3.18.jar!/:5.3.18]
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:769) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:889) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1743) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) [tomcat-embed-core-9.0.60.jar!/:?]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.60.jar!/:?]
    at java.lang.Thread.run(Thread.java:831) [?:?]

To Reproduce


- Steps to reproduce the problem:

**Expected behavior**
Correctly handle java exception logs

**Screenshots**
<!--- If applicable, add screenshots to help explain your problem. -->

**Your Environment**
<!--- Include as many relevant details about the environment you experienced the bug in -->
* Version used:  1.9.6
* Configuration: 
* Environment name and version (e.g. Kubernetes? What version?):  kubernetes 1.17.4
* Server type and version:
* Operating System and version: centos 7.4
* Filters and plugins: multiline

**Additional context**
<!--- How has this issue affected you? What are you trying to accomplish? -->
<!--- Providing context helps us come up with a solution that is most useful in the real world -->
xcrezd commented 2 years ago

Same issue here

RicardoAAD commented 1 year ago

Hello @shalousun

Thanks for bringing this issue to our attention. I did a quick test using the log you provided, and it is easily reproducible even with a newer version of Fluen-Bit.

I checked the java built-in multiline parser, which is working as expected for Google Cloud Java language applications. Unfortunately, it doesn't work with the log example you provided. The built-in java multiline parser uses rules to specify how to match a multiline pattern and perform the concatenation. Each rule has a regex to determine if a line is either the start of a multiline log or if it is part of the stack trace log.

The regex of the Java multiline parser searches for the words "Exception" | "Error" | "Throwable" | "V8 errors stack trace" and when it matches any of these words, Fluent-Bit sets this line as the start of a multiline log. It will concatenate everything that matches with the regex in the other rules that define the rest of the java stack trace. This is the reason why Fluen-Bit shows two lines after processing the log sample that you have provided.

In line0 you have 2022-07-31 23:41:34.668 [http-nio-8080-exec-10] ERROR com.benchmark.springboot.error.RestExceptionHandler@unknownException:77 - Error code 500:{} and in line1 you have java.lang.ArithmeticException: / by zero

When line1 is read, Fluent-Bit sends the line0 to the configured output, and sets line1 as a new start of a multiline log, then concatenates the rest of the stack trace lines to line1.

We wanted to have more details about the code triggering these Exceptions; this is why we wanted to ask for a repo sample of the project/code where you see these Exceptions, so we can study your repro and analyze this issue in detail. As workaround you can use these.

You can use these custom multiline parser that works with the log example you provided. Please check this doc about the custom multiline parsers Config used

[INPUT]
    name tail
    path /tmp/test.log
    read_from_head true
    multiline.parser multiline_java
    tag multiline

[OUTPUT]
    name stdout
    match *
[SERVICE]
    Flush                       1
    Daemon                      Off
    Log_Level                   info
    parsers_file multiline_parser.conf

multiline_parser.conf:

[MULTILINE_PARSER]
    name          multiline_java
    type          regex
    key_content   log
    flush_timeout 2000
    trace_error   on
    # rules   |   state name   | regex pattern                   | next state
    # --------|----------------|---------------------------------------------
    rule       "start_state"    "/^(\d{4}-\d{1,2}-\d{1,2} \d{1,2}:\d{1,2}:\d{1,2}.*)/"       "cont"
    rule       "cont"           "/^([a-zA-Z.]+Exception):\s(.*)$/"                           "cont"
    rule       "cont"           "/^\s+at.*/"                                                 "cont"

Please let us know if the custom multiline example works for you or if you need additional help to tune this example to any other use case you may have.

Regards, Ricardo

github-actions[bot] commented 1 year ago

This issue is stale because it has been open 90 days with no activity. Remove stale label or comment or this will be closed in 5 days. Maintainers can add the exempt-stale label.

github-actions[bot] commented 1 year ago

This issue was closed because it has been stalled for 5 days with no activity.