SecurityStrategy logs twice

[JanWaller]

If I add a second LogBook Filter with Strategy.SECURITY, my calls resulting in 401 get logged twice. Once unfiltered with the whole body by the normal filter and once by the security filter.

I use Spring Boot without Spring Security.
What am I missing?

[JanWaller]

To clarify, I had an error with filter ordering. So my filter causing the 401 response was to low of precedence.

However, with the automated error handling of Spring Boot, the problem remains.
Here, my filter won't be called (I want the "no auth" error message to be visible without auth). So it will be logged twice again. Once by the normal strategy and once by the security strategy.

[whiskeysierra]

Can you try to remove spring-security from your classpath? That should fix it.

Proper fix within Logbook would be to not rely on @ConditionalOnClass:

logbook/logbook-spring-boot-starter/src/main/java/org/zalando/logbook/spring/LogbookAutoConfiguration.java

Line 281 in b2c5cc3

@ConditionalOnClass(SecurityFilterChain.class)

We should rather use @ConditionalOnBean.

[whiskeysierra]

To clarify, I had an error with filter ordering. So my filter causing the 401 response was to low of precedence.

Our setup assumes that the security filter runs in between our two logbook filters, iirc. If your application logic or a filter further down the chain causes 401 then you will see the output twice. There is no easy fix that I can think of right now.

[JanWaller]

I actually have no Spring Security, so I added
@bean
@ConditionalOnProperty(name = "logbook.filter.enabled", havingValue = "true", matchIfMissing = true)
@ConditionalOnMissingBean(name = "unauthorizedLogbookFilter")
public FilterRegistrationBean unauthorizedLogbookFilter(final Logbook logbook) {
final Filter filter = new LogbookFilter(logbook, Strategy.SECURITY);
final FilterRegistrationBean registration = new FilterRegistrationBean<>(filter);
registration.setName("unauthorizedLogbookFilter");
registration.setDispatcherTypes(REQUEST, ASYNC, ERROR);
registration.setOrder(-100); // lower number then spring security (0)
return registration;
}
to my own configuration.

I like the idea of the security strategy to skip the body for 401 responses.
So my custom security filter causes 401 with the same precedence as spring security would.
For the actual request everything looks fine. However, the 401 causes a redirect to /error, which is again logged by logbook. This final logging happens twice. Once by both strategies.

[whiskeysierra]

However, the 401 causes a redirect to /error, which is again logged by logbook. This final logging happens twice.

Error dispatch isn't really properly supported in logbook. You try to remove the ERROR dispatcher type from your customized version. That may help.

[JanWaller]

If I register both filter beans without the error dispatcher, I get the desired result

[sideisra]

I have a similar problem. Would it be a proper solution that the authorizedLogbookFilter (configured via logbook-spring-boot-starter) doesn't log any requests/responses where the response status is 401 or 403? Similar to unauthorizedLogbookFilter which only logs requests/responses with response status 401 or 403.

[whiskeysierra]

@sideisra That requires to delay the logging of the request until the response is available. #296 would support this as a custom strategy.

[whiskeysierra]

For the actual request everything looks fine. However, the 401 causes a redirect to /error, which is again logged by logbook.

@JanWaller Maybe you can just exclude the /error url from Logbook?

[whiskeysierra]

If I register both filter beans without the error dispatcher, I get the desired result

This will become the default as of #437