Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

AbstractRequestLoggingFilter should log actual body even after consuming request parameters on Tomcat 6 [SPR-7913] #12568

Closed
spring-issuemaster opened this issue Jan 26, 2011 · 3 comments

Comments

Projects
None yet
2 participants
@spring-issuemaster
Copy link
Collaborator

commented Jan 26, 2011

Philippe Mouawad opened SPR-7913 and commented

Hello,
I am using Log4jNestedDiagnosticContextFilter to add some logging information.
I noticed that enabling includePayload makes request.getParameter("parameterName") return null values :
<beans:property name="includePayload" value="true" />

I use Spring Security 3.0.5 and set custom filter like this:
<custom-filter ref="log4j-ndc-filter" after="SESSION_MANAGEMENT_FILTER"/>

<beans:bean id="log4j-ndc-filter" class="org.springframework.web.filter.Log4jNestedDiagnosticContextFilter">
<beans:property name="includeClientInfo" value="true" />
<beans:property name="includePayload" value="true" />
<beans:property name="includeQueryString" value="true" />
</beans:bean>

Regards
Philippe


Affects: 3.0.5, 4.1 GA

2 votes, 5 watchers

@spring-issuemaster

This comment has been minimized.

Copy link
Collaborator Author

commented Jan 6, 2015

Tomasz Nurkiewicz commented

I confirm this bug is present up to 4.0.8. The problem was caused by logging filter too early reading request body. Later Tomcat was unable to parse application/x-www-form-urlencoded query parameter from already consumed body.

In 4.1.0 it's somewhat fixed (query parameters are not lost). However logging doesn't work for the same reason: Tomcat consumes body when parsing parameters and logging filter sees empty content. There is caching going on in ContentCachingInputStream, but it doesn't help as it happens on outer layer. Here is a sample application:

@SpringBootApplication
@Controller
public class Application {

	public static void main(String[] args) throws Exception {
		SpringApplication.run(Application.class, args);
	}

	@RequestMapping(value = "/", method = RequestMethod.POST)
	@ResponseBody
	public void handle(@ModelAttribute Form form) {
	}

	@Bean
	public Filter loggingFilter() {
		final CommonsRequestLoggingFilter filter = new CommonsRequestLoggingFilter();
		filter.setIncludePayload(true);
		return filter;
	}
}

class Form {
	int id;
	public int getId() {return id;}
	public void setId(int id) {this.id = id;}
}

Try: curl -v localhost:8080 -d "id=42" with spring-web 4.0.x (Spring Boot 1.1.9) and 4.1.x (Spring Boot 1.2.0). In 4.0.x Form.id is not even populated (== 0). In 4.1.3 id is bound correctly to 42, however logging filter does not show POST body (id=42) at all. Works for other content types.

@spring-issuemaster

This comment has been minimized.

Copy link
Collaborator Author

commented Jan 26, 2015

Brian Clozel commented

Thanks Tomasz Nurkiewicz for this detailed report.
This is fixed for 4.1.5 and 4.2.RC1.

@spring-issuemaster

This comment has been minimized.

Copy link
Collaborator Author

commented Feb 5, 2015

Juergen Hoeller commented

I'm marking this as a refinement that's addressed in 4.1.5 over 4.1 GA where the filter is logging an empty body after request parameters have been consumed, as described. The 'hard' bug has been fixed in 4.1 already, so the change tracked by this issue just makes the logging work for such a case.

Juergen

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.