Details
Critical Description
Having PrettyLogging enabled on InInterceptor, I'm getting the following exception lately.
Is it possible that you could log the response even if an error occurs? Because it's hard to find the rootcause if no soap-xml is logged due to an error inside the pretty-print-logging.
Maybe it's possible to create some fallback and log the response unformatted in case of parsing/formatting errors?
Maybe related to: CXF-6554
2015-09-29 16:07:44,082 WARN o.a.c.p.PhaseInterceptorChain: Interceptor for {http://TheService#{http://TheService}service has thrown exception, unwinding now org.apache.cxf.interceptor.Fault: [com.ctc.wstx.exc.WstxLazyException] Unexpected end of input block in entity reference at [row,col {unknown-source}]: [489,6] at org.apache.cxf.interceptor.LoggingInInterceptor.logInputStream(LoggingInInterceptor.java:225) ~[cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.interceptor.LoggingInInterceptor.logging(LoggingInInterceptor.java:159) ~[cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.interceptor.LoggingInInterceptor.handleMessage(LoggingInInterceptor.java:80) ~[cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.endpoint.ClientImpl.onMessage(ClientImpl.java:798) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1641) [cxf-rt-transports-http-3.1.1.jar:3.1.1] at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1532) [cxf-rt-transports-http-3.1.1.jar:3.1.1] at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1330) [cxf-rt-transports-http-3.1.1.jar:3.1.1] at java.util.zip.DeflaterOutputStream.close(Unknown Source) [?:1.8.0_51] at org.apache.cxf.io.AbstractWrappedOutputStream.close(AbstractWrappedOutputStream.java:77) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.io.AbstractThresholdOutputStream.close(AbstractThresholdOutputStream.java:102) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.io.CacheAndWriteOutputStream.postClose(CacheAndWriteOutputStream.java:56) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.io.CachedOutputStream.close(CachedOutputStream.java:215) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:652) [cxf-rt-transports-http-3.1.1.jar:3.1.1] at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:308) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:514) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:423) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:324) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:277) [cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96) [cxf-rt-frontend-simple-3.1.1.jar:3.1.1] at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:139) [cxf-rt-frontend-jaxws-3.1.1.jar:3.1.1] at com.sun.proxy.$Proxy186.service(Unknown Source) [?:?] at sun.reflect.GeneratedMethodAccessor235.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_51] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_51] at org.springframework.expression.spel.support.ReflectiveMethodExecutor.execute(ReflectiveMethodExecutor.java:112) [spring-expression-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.expression.spel.ast.MethodReference.getValueInternal(MethodReference.java:102) [spring-expression-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.expression.spel.ast.MethodReference.access$000(MethodReference.java:49) [spring-expression-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.expression.spel.ast.MethodReference$MethodValueRef.getValue(MethodReference.java:342) [spring-expression-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.expression.spel.ast.CompoundExpression.getValueInternal(CompoundExpression.java:88) [spring-expression-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.expression.spel.ast.SpelNodeImpl.getTypedValue(SpelNodeImpl.java:131) [spring-expression-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.expression.spel.standard.SpelExpression.getValue(SpelExpression.java:330) [spring-expression-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.integration.util.AbstractExpressionEvaluator.evaluateExpression(AbstractExpressionEvaluator.java:164) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.util.MessagingMethodInvokerHelper.processInternal(MessagingMethodInvokerHelper.java:276) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.util.MessagingMethodInvokerHelper.process(MessagingMethodInvokerHelper.java:142) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.handler.MethodInvokingMessageProcessor.processMessage(MethodInvokingMessageProcessor.java:75) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.handler.ServiceActivatingHandler.handleRequestMessage(ServiceActivatingHandler.java:71) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.handler.AbstractReplyProducingMessageHandler.handleMessageInternal(AbstractReplyProducingMessageHandler.java:99) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.handler.AbstractMessageHandler.handleMessage(AbstractMessageHandler.java:78) [spring-integration-core-4.1.4.RELEASE.jar:?] at sun.reflect.GeneratedMethodAccessor186.invoke(Unknown Source) ~[?:?] at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:1.8.0_51] at java.lang.reflect.Method.invoke(Unknown Source) ~[?:1.8.0_51] at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) [spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190) [spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) [spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.integration.monitor.SimpleMessageHandlerMetrics.handleMessage(SimpleMessageHandlerMetrics.java:107) [spring-integration-jmx-4.1.4.RELEASE.jar:?] at org.springframework.integration.monitor.SimpleMessageHandlerMetrics.invoke(SimpleMessageHandlerMetrics.java:87) [spring-integration-jmx-4.1.4.RELEASE.jar:?] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) [spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207) [spring-aop-4.1.6.RELEASE.jar:4.1.6.RELEASE] at com.sun.proxy.$Proxy206.handleMessage(Unknown Source) [?:?] at org.springframework.integration.dispatcher.AbstractDispatcher.tryOptimizedDispatch(AbstractDispatcher.java:116) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.dispatcher.UnicastingDispatcher.doDispatch(UnicastingDispatcher.java:101) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.dispatcher.UnicastingDispatcher.dispatch(UnicastingDispatcher.java:97) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.channel.AbstractSubscribableChannel.doSend(AbstractSubscribableChannel.java:77) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:286) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:115) [spring-messaging-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.messaging.core.GenericMessagingTemplate.doSendAndReceive(GenericMessagingTemplate.java:150) [spring-messaging-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.messaging.core.GenericMessagingTemplate.doSendAndReceive(GenericMessagingTemplate.java:45) [spring-messaging-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.messaging.core.AbstractMessagingTemplate.sendAndReceive(AbstractMessagingTemplate.java:42) [spring-messaging-4.1.6.RELEASE.jar:4.1.6.RELEASE] at org.springframework.integration.gateway.MessagingGatewaySupport.doSendAndReceive(MessagingGatewaySupport.java:331) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.gateway.MessagingGatewaySupport.sendAndReceiveMessage(MessagingGatewaySupport.java:302) [spring-integration-core-4.1.4.RELEASE.jar:?] at org.springframework.integration.ip.tcp.connection.TcpNioConnection.sendToChannel(TcpNioConnection.java:357) [spring-integration-ip-4.1.4.RELEASE.jar:?] at org.springframework.integration.ip.tcp.connection.TcpNioConnection.run(TcpNioConnection.java:230) [spring-integration-ip-4.1.4.RELEASE.jar:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:1.8.0_51] at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:1.8.0_51] at java.lang.Thread.run(Unknown Source) [?:1.8.0_51] Caused by: com.ctc.wstx.exc.WstxLazyException: [com.ctc.wstx.exc.WstxLazyException] Unexpected end of input block in entity reference at [row,col {unknown-source}]: [489,6] at com.ctc.wstx.exc.WstxLazyException.throwLazily(WstxLazyException.java:45) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at com.ctc.wstx.sr.StreamScanner.throwLazyError(StreamScanner.java:728) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at com.ctc.wstx.sr.BasicStreamReader.safeFinishToken(BasicStreamReader.java:3678) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at com.ctc.wstx.sr.BasicStreamReader.getText(BasicStreamReader.java:860) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:752) ~[cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:701) ~[cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:625) ~[cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.interceptor.AbstractLoggingInterceptor.writePayload(AbstractLoggingInterceptor.java:168) ~[cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.interceptor.LoggingInInterceptor.logInputStream(LoggingInInterceptor.java:221) ~[cxf-core-3.1.1.jar:3.1.1] ... 81 more Caused by: com.ctc.wstx.exc.WstxEOFException: Unexpected end of input block in entity reference at [row,col {unknown-source}]: [489,6] at com.ctc.wstx.sr.StreamScanner.throwUnexpectedEOB(StreamScanner.java:699) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at com.ctc.wstx.sr.StreamScanner.loadMoreFromCurrent(StreamScanner.java:1071) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at com.ctc.wstx.sr.StreamScanner.getNextCharFromCurrent(StreamScanner.java:810) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at com.ctc.wstx.sr.StreamScanner.resolveCharEnt(StreamScanner.java:2360) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at com.ctc.wstx.sr.StreamScanner.resolveCharOnlyEntity(StreamScanner.java:1347) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at com.ctc.wstx.sr.BasicStreamReader.readTextSecondary(BasicStreamReader.java:4715) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at com.ctc.wstx.sr.BasicStreamReader.finishToken(BasicStreamReader.java:3722) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at com.ctc.wstx.sr.BasicStreamReader.safeFinishToken(BasicStreamReader.java:3676) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at com.ctc.wstx.sr.BasicStreamReader.getText(BasicStreamReader.java:860) ~[woodstox-core-asl-4.4.1.jar:4.4.1] at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:752) ~[cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:701) ~[cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:625) ~[cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.interceptor.AbstractLoggingInterceptor.writePayload(AbstractLoggingInterceptor.java:168) ~[cxf-core-3.1.1.jar:3.1.1] at org.apache.cxf.interceptor.LoggingInInterceptor.logInputStream(LoggingInInterceptor.java:221) ~[cxf-core-3.1.1.jar:3.1.1] ... 81 more
The error occurs when the soap response in LoggingInInterceptor has a html "dot" encoded string: "•". And if the message is very long, the truncation might happen in between this html endocing.
See the following example: the exception stating [489,3] explicit refers to "", which is the cut html encoding.
In this case, the exception above is thrown.
<SOAP:Envelope xmlns:SOAP="http://schemas.xmlsoap.org/soap/envelope/"><SOAP:Body><...>
• some text
• some more text

</..>
</SOAP:Body>
</SOAP:Envelope>
Would it be possible to fix it in a future version? Pretty logging is crucial, and some of our productive applications broke in the past due to this logging exception, and breaks the application workflow completely. (that's why I raised the issue to critical).
