[CXF-5829] Logging interceptors fail with large inbound messages (XML document structures must start and end within the same entity)

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 2.6.14
• Fix Version/s: 2.6.15
• Component/s: Core
• Labels: logging xml

Environment

JDK 1.6.0-45 on Linux and Windows
JBoss EAP 5.1.1

• Estimated Complexity: Unknown
• Assignee: Daniel Kulp
• Reporter: Patrick Decat
• Created: 27/Jun/14 10:40
• Updated: 11/Apr/16 11:43
• Resolved: 01/Jul/14 17:13

Description

Upgrading from CXF 2.6.13 to 2.6.14 prevents receiving large messages if logging inbound messages is enabled.
It fails with "XML document structures must start and end within the same entity":

JBOSS 27 juin 2014 12:12:18.418 [http-0.0.0.0-8080-1] ERROR f.g.p.e.e.s.i.CourrierEditiqueServiceImpl - org.xml.sax.SAXParseException: XML document structures must start and end within the same entity.
javax.xml.ws.soap.SOAPFaultException: org.xml.sax.SAXParseException: XML document structures must start and end within the same entity.
            at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:158) ~[cxf-rt-frontend-jaxws-2.6.14.jar!/:2.6.14]
            at com.sun.proxy.$Proxy426.restitutionCourrierBinaire(Unknown Source) ~[na:na]
            at fr.mypackage.MyImpl.getPdf(MyImpl.java:46) ~[mypackage-impl.jar!/:na]
            at fr.mypackage.MyPdfController.openPDF(MyPdfController.java:103) [mypackage.jar!/:na]
            at fr.mypackage.MyPdfController.getPdf(CourrierPdfController.java:66) [mypackage.jar!/:na]
            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.6.0_45]
            at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) ~[na:1.6.0_45]
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) ~[na:1.6.0_45]
            at java.lang.reflect.Method.invoke(Method.java:597) ~[na:1.6.0_45]
            at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:176) [spring-web-3.2.9.RELEASE.jar!/:3.2.9.RELEASE]
            at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:440) [spring-webmvc-3.2.9.RELEASE.jar!/:3.2.9.RELEASE]
            at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:428) [spring-webmvc-3.2.9.RELEASE.jar!/:3.2.9.RELEASE]
            at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:919) [spring-webmvc-3.2.9.RELEASE.jar!/:3.2.9.RELEASE]
            at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:851) [spring-webmvc-3.2.9.RELEASE.jar!/:3.2.9.RELEASE]
            at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:953) [spring-webmvc-3.2.9.RELEASE.jar!/:3.2.9.RELEASE]
            at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:844) [spring-webmvc-3.2.9.RELEASE.jar!/:3.2.9.RELEASE]
            at javax.servlet.http.HttpServlet.service(HttpServlet.java:617) [servlet-api.jar!/:na]
            at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:829) [spring-webmvc-3.2.9.RELEASE.jar!/:3.2.9.RELEASE]
            at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) [servlet-api.jar!/:na]
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [jbossweb.jar!/:na]
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [jbossweb.jar!/:na]
            at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:154) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:199) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:110) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at fr.mypackage.MyFilterSecurityInterceptor.doFilter(MyFilterSecurityInterceptorptor.java:222) [mysecurity-impl.jar!/:na]
            at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160) [spring-security-web-3.2.4.RELEASE.jar!/:3.2.4.RELEASE]
            at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:343) [spring-web-3.2.9.RELEASE.jar!/:3.2.9.RELEASE]
            at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:260) [spring-web-3.2.9.RELEASE.jar!/:3.2.9.RELEASE]
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [jbossweb.jar!/:na]
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [jbossweb.jar!/:na]
            at org.jboss.web.tomcat.filters.ReplyHeaderFilter.doFilter(ReplyHeaderFilter.java:96) [jboss-web-service.jar!/:5.1.1 (build: SVNTag=JBPAPP_5_1_1 date=201105171607)]
            at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235) [jbossweb.jar!/:na]
            at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [jbossweb.jar!/:na]
            at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:235) [jbossweb.jar!/:na]
            at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [jbossweb.jar!/:na]
            at org.jboss.web.tomcat.security.SecurityAssociationValve.invoke(SecurityAssociationValve.java:183) [jboss-web-service.jar!/:5.1.1 (build: SVNTag=JBPAPP_5_1_1 date=201105171607)]
            at org.jboss.web.tomcat.security.JaccContextValve.invoke(JaccContextValve.java:95) [jboss-web-service.jar!/:5.1.1 (build: SVNTag=JBPAPP_5_1_1 date=201105171607)]
            at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.process(SecurityContextEstablishmentValve.java:126) [jboss-web-service.jar!/:5.1.1 (build: SVNTag=JBPAPP_5_1_1 date=201105171607)]
            at org.jboss.web.tomcat.security.SecurityContextEstablishmentValve.invoke(SecurityContextEstablishmentValve.java:70) [jboss-web-service.jar!/:5.1.1 (build: SVNTag=JBPAPP_5_1_1 date=201105171607)]
            at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [jbossweb.jar!/:na]
            at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [jbossweb.jar!/:na]
            at org.jboss.web.tomcat.service.jca.CachedConnectionValve.invoke(CachedConnectionValve.java:158) [jboss-web-service.jar!/:5.1.1 (build: SVNTag=JBPAPP_5_1_1 date=201105171607)]
            at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [jbossweb.jar!/:na]
            at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:330) [jbossweb.jar!/:na]
            at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:829) [jbossweb.jar!/:na]
            at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:599) [jbossweb.jar!/:na]
            at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:451) [jbossweb.jar!/:na]
            at java.lang.Thread.run(Thread.java:662) [na:1.6.0_45]
Caused by: javax.xml.transform.TransformerException: org.xml.sax.SAXParseException: XML document structures must start and end within the same entity.
            at org.apache.xalan.transformer.TransformerIdentityImpl.transform(TransformerIdentityImpl.java:500) ~[na:na]
            at org.apache.cxf.interceptor.AbstractLoggingInterceptor.writePayload(AbstractLoggingInterceptor.java:164) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.interceptor.LoggingInInterceptor.logInputStream(LoggingInInterceptor.java:189) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.interceptor.LoggingInInterceptor.logging(LoggingInInterceptor.java:136) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.interceptor.LoggingInInterceptor.handleMessage(LoggingInInterceptor.java:79) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:263) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.endpoint.ClientImpl.onMessage(ClientImpl.java:845) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1705) ~[cxf-rt-transports-http-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1538) ~[cxf-rt-transports-http-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1445) ~[cxf-rt-transports-http-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.io.CacheAndWriteOutputStream.postClose(CacheAndWriteOutputStream.java:56) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.io.CachedOutputStream.close(CachedOutputStream.java:229) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:660) ~[cxf-rt-transports-http-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:263) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:570) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:479) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:382) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:335) ~[cxf-api-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96) ~[cxf-rt-frontend-simple-2.6.14.jar!/:2.6.14]
            at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:136) ~[cxf-rt-frontend-jaxws-2.6.14.jar!/:2.6.14]
            ... 66 common frames omitted
Caused by: org.xml.sax.SAXParseException: XML document structures must start and end within the same entity.
            at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(AbstractSAXParser.java:1231) ~[na:1.6.0_45]
            at org.apache.xalan.transformer.TransformerIdentityImpl.transform(TransformerIdentityImpl.java:483) ~[na:na]
            ... 87 common frames omitted

No issue with CXF 2.6.13.

Probably provoked by CXF-5635.

Increasing the limit from the default 100kB is a work-around.

Regards,
Patrick.

Issue Links

• is related to: CXF-6554 Exception thrown in LoggingInInterceptor
• relates to: CXF-5761 InInterceptor throws exception with PrettyLogging and big message size