Filebeat Multiline Java Stack Trace


#1

Hey there,

I try to find out how to use Filebeat for my Java Log files. Actually it's not a big deal, except for my problems with multiline messages, because my Java Logs include Stack Traces.

Can someone help me to find the right pattern for my case?

Currently I am using this pattern, which combines all rows starting with spaces and "Caused by" (from this example). But unfortunately it does not combine the Stack Trace with the Java Log, instead it just combines the Stack Trace to one message, leaving the Java Error Log without Stack Trace.

Filebeat config

multiline.pattern: '^[[:space:]]+(at|\.{3})\b|^Caused by:'
multiline.negate: false
multiline.match: after

Exampe Java Log with Stacktrace

2018-05-31 08:44:22,771 ERROR com.zettler.ec.jsf.common.security.spring.ZettlerAuthenticationProcessingFilter - An internal error occurred while trying to authenticate the user.
org.springframework.security.authentication.InternalAuthenticationServiceException: User ist in Datenbank nicht angelegt.
	at org.springframework.security.authentication.dao.DaoAuthenticationProvider.retrieveUser(DaoAuthenticationProvider.java:110)
	at org.springframework.security.authentication.dao.AbstractUserDetailsAuthenticationProvider.authenticate(AbstractUserDetailsAuthenticationProvider.java:132)
	at org.springframework.security.authentication.ProviderManager.authenticate(ProviderManager.java:156)
	at com.zettler.ec.jsf.common.security.spring.ZettlerAuthenticationProcessingFilter.attemptAuthentication(ZettlerAuthenticationProcessingFilter.java:89)
	at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:211)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
	at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:110)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
	at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:50)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
	at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87)
	at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
	at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192)
	at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160)
	at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:347)
	at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:263)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:94)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:504)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
	at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:676)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:502)
	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1132)
	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:684)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1539)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1495)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: User ist in Datenbank nicht angelegt.
	at com.zettler.ec.jsf.common.security.spring.MfxUserDetailsService.loadUserByUsername(MfxUserDetailsService.java:80)
	at org.springframework.security.authentication.dao.DaoAuthenticationProvider.retrieveUser(DaoAuthenticationProvider.java:102)
	... 34 more

(Christian Dahlqvist) #2

Does the timestamp example in the documentation now work for this?


#3

It does! But it does not add the Stack Trace to the previous Java Error Log.


(Christian Dahlqvist) #4

I am not sure I follow. Can you show a full example?


#5

No problem, I am sorry for my unprecise description... this is my first IT project.

I use an Filebeats > Logstash > Elasticsearch (> Kibana) configuration.

The idea is, to let Filebeats extract the logs from the hundreds of .log-files we have in our storages and send it to Logstash, where it gets mapped/ structured in the for Elasticsearch appropriate way.

Now (for testing purposes) my Logstash receives the messages of the Filebeat and prints them in the console (stdout).

When I'm starting filebeat (the multiline.pattern) and logstash, then logstash prints out for each Error Stack Trace Log, two different JSON messages. One containing the first part (Error Log):

2018-05-31 21:27:33,065 ERROR org.apache.catalina.core.ContainerBase.[Catalina].[localhost].[/mfx##20180524121538_19.1.15.4243].[AutoRegisteredResourceServlet] - Servlet.service() for servlet [AutoRegisteredResourceServlet] in context with path [/mfx##20180524121538_19.1.15.4243] threw exception

The other one, containing the second part (Stack Trace):

java.lang.IllegalStateException: getAttribute: Session already invalidated
at org.apache.catalina.session.StandardSession.getAttribute(StandardSession.java:1191)
at org.apache.catalina.session.StandardSessionFacade.getAttribute(StandardSessionFacade.java:103)
at base.web.session_countdown.HttpSessionRefreshFilter.getSessionAttribute(HttpSessionRefreshFilter.java:134)
at base.web.session_countdown.HttpSessionRefreshFilter.doRefreshActions(HttpSessionRefreshFilter.java:82)
at base.web.session_countdown.HttpSessionRefreshFilter.doFilter(HttpSessionRefreshFilter.java:59)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:199)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:110)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:50)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87)
at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192)
at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160)
at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:347)
at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:263)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:94)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:504)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:676)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:502)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1132)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:684)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1539)
at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1495)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:748)

For me, it would be better to have the whole Stack Trace togheter with the Error Log.

Thank you so much for your time!


(Kumar Saurabh) #6

I am also following response closely as I tried to do this but could not. Thanks for posting it


(Christian Dahlqvist) #7

The pattern I linked to, which looks for a line starting with a timestamp and adds all subsequent lines that do not should as far as I understand handle that and group it the way you want.


#8

Thank you Christian.

Yes, this was actually also my first tought. I tried it, but all what happened is that the whole Log file was grouped to one message.

Now I tried:

multiline.pattern: '[0-9]{4}-[0-9]{2}-[0-9]{2}'
multiline.negate: true
multiline.match: after

And it worked out, except for the last line (log), which was "ignored", because it was not printed in the console.


(Christian Dahlqvist) #9

This should be sent on once it has timed out, which should happen after 5 seconds by default.


#10

Actually nothing happens, even when I define that multiline.timeout: 5s.


#12

So, after 2 weeks I still haven't found the right solution to my problem.

Example Error Log

2018-05-31 08:44:22,771 ERROR com.zettler.ec.jsf.common.security.spring.ZettlerAuthenticationProcessingFilter - An internal error occurred while trying to authenticate the user.
org.springframework.security.authentication.InternalAuthenticationServiceException: User ist in Datenbank nicht angelegt.
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1539)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1495)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: User ist in Datenbank nicht angelegt.
	at com.zettler.ec.jsf.common.security.spring.MfxUserDetailsService.loadUserByUsername(MfxUserDetailsService.java:80)
	at org.springframework.security.authentication.dao.DaoAuthenticationProvider.retrieveUser(DaoAuthenticationProvider.java:102)
	... 34 more

Current state

What the following configuration does, is that it merges any line that begins with whitespace up to the previous line.

multiline.pattern: '^[[:space:]]+(at|\.{3})\b|^Caused by:'
multiline.negate: false
multiline.match: after

The problem is, that I would have now two separated "Logs" or "Events" (the product of the Filebeat) for actually one Error Log.

In the case of the example error log from above, the Filebeat would do the following...

One log with (Java Log):

2018-05-31 08:44:22,771 ERROR com.zettler.ec.jsf.common.security.spring.ZettlerAuthenticationProcessingFilter - An internal error occurred while trying to authenticate the user.

And, one log with (the Stack Trace belonging to the Java Log):

org.springframework.security.authentication.InternalAuthenticationServiceException: User ist in Datenbank nicht angelegt.
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1539)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1495)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.RuntimeException: User ist in Datenbank nicht angelegt.
	at com.zettler.ec.jsf.common.security.spring.MfxUserDetailsService.loadUserByUsername(MfxUserDetailsService.java:80)
	at org.springframework.security.authentication.dao.DaoAuthenticationProvider.retrieveUser(DaoAuthenticationProvider.java:102)
	... 34 more

Target state

Having a configuration that merges all the Stack Trace lines to the belonging Error Log - having 1 Log for each Log and not 2, in case of Logs with Stack Traces.

.

I hope that my problem is more clear now.


#13

try it,be care for "^"
multiline.pattern: '^([0-9]{4}-[0-9]{2}-[0-9]{2})'
multiline.negate: true
multiline.match: after

if delay to long or log to long,add these options
multiline.timeout: 120s #default 5s
multiline.max_lines: 10000 #default 500

more about options see this https://www.elastic.co/guide/en/beats/filebeat/current/multiline-examples.html


#14

Thank you, that worked out!


(system) #15

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.