Add support for filtering stack traces in the log4j2 implementation #167

tobiasstadler · 2022-02-07T13:48:46Z

This is similar to what %xEx{filters(...)} does.

apmmachine · 2022-02-07T13:57:39Z

💚 Build Succeeded

the below badges are clickable and redirect to their specific view in the CI or DOCS

Expand to view the summary

Build stats

Start Time: 2022-04-27T10:32:24.487+0000
Duration: 36 min 1 sec

Test stats 🧪

Test	Results
Failed	0
Passed	204
Skipped	0
Total	204

🤖 GitHub comments

To re-run your PR in the CI, just comment with:

/test : Re-trigger the build.
run elasticsearch-ci/docs : Re-trigger the docs validation. (use unformatted text in the comment!)

tobiasstadler · 2022-02-09T11:52:03Z

@felixbarny / @eyalkoren Since version 1.29.0 of the Java agent was released recently, could you please spare some time to provide feedback on this PR?

tobiasstadler · 2022-03-10T07:16:47Z

ping

felixbarny · 2022-03-10T07:48:04Z

What are some of the use cases for wanting to filter out a stack frame?
Using regex seems like it can be quite heavy on performance. Would matching via String#contains be good enough? If not, maybe something like the WildcardMatcher from the Java agent that uses String#regionMatches?

tobiasstadler · 2022-03-10T08:04:29Z

My use case is to filter out (most of) the framework stack frames, which can be very noisy on an application server and usually do not add valuable information.

e.g. I would like to compress

com.example.SomeException: Some Message
	at com.example.Bar.foo(Bar.java:321)
	at com.example.Foo.bar(Foo.java:123)
	at com.example.Foo$Proxy$_$$_WeldClientProxy.bar(Unknown Source)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:138)
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:151)
	at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:546)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:435)
	at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:396)
	at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:398)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:365)
	at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:338)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:440)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:229)
	at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:135)
	at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:358)
	at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:138)
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:215)
	at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:245)
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:61)
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:590)
	at io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:74)
	at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:129)
	at org.apache.logging.log4j.web.Log4jServletFilter.doFilter(Log4jServletFilter.java:71)
	at io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:61)
	at io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:131)
	at io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:84)
	at io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:62)
	at io.undertow.servlet.handlers.ServletChain$1.handleRequest(ServletChain.java:68)
	at io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)
	at org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
	at io.undertow.servlet.handlers.RedirectDirHandler.handleRequest(RedirectDirHandler.java:68)
	at io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:117)
	at io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:57)
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
	at io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:46)
	at io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:64)
	at io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:60)
	at io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:77)
	at io.undertow.security.handlers.NotificationReceiverHandler.handleRequest(NotificationReceiverHandler.java:50)
	at io.undertow.security.handlers.AbstractSecurityContextAssociationHandler.handleRequest(AbstractSecurityContextAssociationHandler.java:43)
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
	at org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
	at org.wildfly.extension.undertow.deployment.GlobalRequestControllerHandler.handleRequest(GlobalRequestControllerHandler.java:68)
	at io.undertow.servlet.handlers.SendErrorPageHandler.handleRequest(SendErrorPageHandler.java:52)
	at io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)
	at io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:275)
	at io.undertow.servlet.handlers.ServletInitialHandler.access$100(ServletInitialHandler.java:79)
	at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:134)
	at io.undertow.servlet.handlers.ServletInitialHandler$2.call(ServletInitialHandler.java:131)
	at io.undertow.servlet.core.ServletRequestContextThreadSetupAction$1.call(ServletRequestContextThreadSetupAction.java:48)
	at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43)
	at org.wildfly.extension.undertow.security.SecurityContextThreadSetupAction.lambda$create$0(SecurityContextThreadSetupAction.java:105)
	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1551)
	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1551)
	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1551)
	at org.wildfly.extension.undertow.deployment.UndertowDeploymentInfoService$UndertowThreadSetupAction.lambda$create$0(UndertowDeploymentInfoService.java:1551)
	at io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:255)
	at io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:79)
	at io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:100)
	at io.undertow.server.Connectors.executeRootHandler(Connectors.java:387)
	at io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:852)
	at org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
	at org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1990)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
	at org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
	at org.xnio.XnioWorker$WorkerThreadFactory$1$1.run(XnioWorker.java:1280)
	at java.lang.Thread.run(Thread.java:750)

into something like

com.example.SomeException: Some Message
	at com.example.Bar.foo(Bar.java:321)
	at com.example.Foo.bar(Foo.java:123)
	... suppressed x lines
	at java.lang.Thread.run(Thread.java:750)

This should increase readability (especially when there are also nested exceptions) and reduce storage costs.

I am aware that in some (rare) case we might loose valuable stack frames, but overall I think its worth the downside.

tobiasstadler · 2022-03-10T08:05:06Z

I will have a look into String.contains

felixbarny

LGTM
@eyalkoren could you also have a look?

HaloFour · 2022-04-04T21:44:19Z

Oops, didn't see this PR out there. I just submitted something similar except that it uses log4j2's PatternFormatter to render the Throwable and should support all of the patterns that log4j2 supports. I'll test to ensure that it also works with filters.

#177

I've confirmed that it works with filters, e.g. %xEx{filters(java.lang.reflect)}

eyalkoren · 2022-04-05T13:12:33Z

@tobiasstadler please take a look at #177 - would you be able to use this approach for your needs?
Since your implementation is log4j2-specific as well, it seems like a good approach for utilizing inherent log4j2 stuff with some more options.
I didn't review both yet, but in general, same overhead that would be applied through using the same capabilities in log4j2 is acceptable and we need to see if and how stack-as-array is supported.
Please let me know what you think. Thanks!

tobiasstadler · 2022-04-05T15:25:42Z

@eyalkoren My solution uses contains while the log4j implementation uses startsWith. So #177 will only solve my problem partially.

HaloFour · 2022-04-05T16:09:10Z

@tobiasstadler

My solution uses contains while the log4j implementation uses startsWith. So #177 will only solve my problem partially.

You could roll your own LogEventPatternConverter and have it filter out the frames in that manner and use that in the exception pattern. It is more involved but it gives you total control over the format. That's honestly how I'm likely to use that PR if it's merged as I am interested in getting close to the logstash ShortenedThrowableConverter and log4j2 doesn't offer most of those features and I think trying to build that into EcsJsonSerializer would be ... involved.

It's a bit of a shame that the throwable converters that ship with log4j2 aren't really designed to be extended, that would have made it pretty trivial to build a custom one that just tweaks the behavior of filtering out stack frames.

eyalkoren · 2022-04-06T06:38:27Z

@eyalkoren My solution uses contains while the log4j implementation uses startsWith. So #177 will only solve my problem partially.

Yes, I am aware. Yours is more performant. This is why I emphasized that in general, same overhead that would be applied through using the same capabilities in log4j2 is acceptable.

You could roll your own LogEventPatternConverter and have it filter out the frames in that manner and use that in the exception pattern. It is more involved but it gives you total control over the format. That's honestly how I'm likely to use that PR if it's merged

Could that be a solution that satisfies all? What if you take the more efficient approach from this PR and use it within a custom LogEventPatternConverter, which is added to the ecs-logging lib as well (with a custom pattern) and use the log4j-native configuration approach from #167 ?
Does this make sense?

@tobiasstadler just an example where providing the maximum flexibility is preferable- assume that we use the filtering approach from this PR only and it solves what it needs to perfectly. However, for another user the most important thing is to put a hard limit on the number of stack trace elements they want to get logged. The general-purpose approach allows that with the builtin converter even though we didn't think of that.

tobiasstadler · 2022-04-07T10:59:28Z

I just want to "exclude" stack frames from stack traces that match some list of patterns. I am fine with anything providing support for this.

eyalkoren · 2022-04-26T15:48:10Z

@tobiasstadler could you port your desired implementation into a LogEventPatternConverter and find the best approach to load it on demand, as org.apache.logging.log4j.core.config.plugins.Plugin or otherwise, so it would work well with #177 ?

felixbarny · 2022-04-26T15:52:08Z

I'm not convinced that we should add custom implementations for LogEventPatternConverter in ecs-logging-java. Wouldn't it be enough to be able to use custom LogEventPatternConverter implementations that live in the application's code base?

eyalkoren · 2022-04-27T05:18:04Z

Wouldn't it be enough to be able to use custom LogEventPatternConverter implementations that live in the application's code base?

It would, but if others can benefit from it, why not have it here? After all, it is very relevant to log manipulation that is probably common for ECS users. Are you worried about the maintenance burden? That indeed has overhead, but if we make it pluggable, it provides a nice encapsulation and I think it could be a nice example for other users of how it can be done.
What about placing it in a separate module dedicated for plugins?

felixbarny · 2022-04-27T06:09:45Z

I just think adding utilities is not in scope of this project and could be a slippery slope. I agree it's useful but not specific to ECS. Maybe upstream log4j2 would be a better home for that LogEventPatternConverter.

eyalkoren · 2022-04-28T04:47:24Z

@tobiasstadler we decided to go with the generic approach of #177 because it is extensible very flexibly, as demonstrated through CustomExceptionPatternConverter and the corresponding EcsLayoutWithExceptionPatternTest.

With that, you can apply any custom formatting, like the one in this PR. Would that work well for your use case?

tobiasstadler · 2022-04-29T05:27:52Z

I will have a look

Added support for filtering stack traces in the log4j2 implementation

9bec925

github-actions bot added agent-java community Issues and PRs created by the community triage Issues and PRs that need to be triaged labels Feb 7, 2022

Use indexOf instead of regex

acb9f7a

felixbarny approved these changes Mar 14, 2022

View reviewed changes

felixbarny requested a review from eyalkoren March 14, 2022 07:34

AlexanderWert added the 8.3-candidate label Mar 28, 2022

eyalkoren mentioned this pull request Apr 5, 2022

Configurable exception pattern for log4j2 #177

Merged

tobiasstadler closed this Apr 29, 2022

tobiasstadler deleted the log4j2-filter-stacktrace branch April 29, 2022 05:33

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add support for filtering stack traces in the log4j2 implementation #167

Add support for filtering stack traces in the log4j2 implementation #167

tobiasstadler commented Feb 7, 2022

apmmachine commented Feb 7, 2022 •

edited

Loading

Build stats

Test stats 🧪

tobiasstadler commented Feb 9, 2022

tobiasstadler commented Mar 10, 2022

felixbarny commented Mar 10, 2022

tobiasstadler commented Mar 10, 2022

tobiasstadler commented Mar 10, 2022

felixbarny left a comment

HaloFour commented Apr 4, 2022 •

edited

Loading

eyalkoren commented Apr 5, 2022

tobiasstadler commented Apr 5, 2022

HaloFour commented Apr 5, 2022 •

edited

Loading

eyalkoren commented Apr 6, 2022

tobiasstadler commented Apr 7, 2022

eyalkoren commented Apr 26, 2022

felixbarny commented Apr 26, 2022

eyalkoren commented Apr 27, 2022

felixbarny commented Apr 27, 2022

eyalkoren commented Apr 28, 2022

tobiasstadler commented Apr 29, 2022

Add support for filtering stack traces in the log4j2 implementation #167

Add support for filtering stack traces in the log4j2 implementation #167

Conversation

tobiasstadler commented Feb 7, 2022

apmmachine commented Feb 7, 2022 • edited Loading

💚 Build Succeeded

Build stats

Test stats 🧪

🤖 GitHub comments

tobiasstadler commented Feb 9, 2022

tobiasstadler commented Mar 10, 2022

felixbarny commented Mar 10, 2022

tobiasstadler commented Mar 10, 2022

tobiasstadler commented Mar 10, 2022

felixbarny left a comment

Choose a reason for hiding this comment

HaloFour commented Apr 4, 2022 • edited Loading

eyalkoren commented Apr 5, 2022

tobiasstadler commented Apr 5, 2022

HaloFour commented Apr 5, 2022 • edited Loading

eyalkoren commented Apr 6, 2022

tobiasstadler commented Apr 7, 2022

eyalkoren commented Apr 26, 2022

felixbarny commented Apr 26, 2022

eyalkoren commented Apr 27, 2022

felixbarny commented Apr 27, 2022

eyalkoren commented Apr 28, 2022

tobiasstadler commented Apr 29, 2022

apmmachine commented Feb 7, 2022 •

edited

Loading

HaloFour commented Apr 4, 2022 •

edited

Loading

HaloFour commented Apr 5, 2022 •

edited

Loading