Return-Path: X-Original-To: apmail-cxf-issues-archive@www.apache.org Delivered-To: apmail-cxf-issues-archive@www.apache.org Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by minotaur.apache.org (Postfix) with SMTP id EBA13110F4 for ; Thu, 22 May 2014 17:47:01 +0000 (UTC) Received: (qmail 52537 invoked by uid 500); 22 May 2014 17:47:01 -0000 Delivered-To: apmail-cxf-issues-archive@cxf.apache.org Received: (qmail 52499 invoked by uid 500); 22 May 2014 17:47:01 -0000 Mailing-List: contact issues-help@cxf.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@cxf.apache.org Delivered-To: mailing list issues@cxf.apache.org Received: (qmail 52432 invoked by uid 99); 22 May 2014 17:47:01 -0000 Received: from arcas.apache.org (HELO arcas.apache.org) (140.211.11.28) by apache.org (qpsmtpd/0.29) with ESMTP; Thu, 22 May 2014 17:47:01 +0000 Date: Thu, 22 May 2014 17:47:01 +0000 (UTC) From: "member sound (JIRA)" To: issues@cxf.apache.org Message-ID: In-Reply-To: References: Subject: [jira] [Created] (CXF-5761) InInterceptor throws exception with PrettyLogging and big message size MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 7bit X-JIRA-FingerPrint: 30527f35849b9dde25b450d4833f0394 member sound created CXF-5761: --------------------------------- Summary: InInterceptor throws exception with PrettyLogging and big message size Key: CXF-5761 URL: https://issues.apache.org/jira/browse/CXF-5761 Project: CXF Issue Type: Bug Components: Core Affects Versions: 3.0.0 Environment: Java 1.7 Reporter: member sound Since 2.7.11 (and also in 3.0.0) I have problems with pretty print. Client client = ClientProxy.getClient(port); LoggingInInterceptor loggingInInterceptor = new LoggingInInterceptor(); loggingInInterceptor.setPrettyLogging(true); client.getInInterceptors().add(loggingInInterceptor); If I enable pretty print, 2.7.10 works as expected. Any version above throws an exception. But ONLY if prettylogging on ininterceptor is enabled. Disabling it will log the message normally. The root cause is in cxf-core. I cannot post the entire webservice response as it is not public. Though it is obvious that only the version change causes this error. But an excerpt of the complaining element is: [...] xFuGPYCHgC5vICGiajJE9VJilViIlUaNUmKVWIiVRo1SYpVYiJVGjVJilViIlUaNUmKV Here the closing tag is not found because the message probably exceeds the maximum allowed length for logging and is truncated. There must be a difference in handling this since 2.7.10, as with this old version a too long and truncated soap response is not a problem! What I noticed: the logging by InInterceptor is missing the "(message truncated to X bytes)" statement. If I create the interceptor with a bigger threshold, the error is also not thrown: new LoggingInInterceptor(1000000); //OK as it is bigger than [1,49152] stated in the exception Or just taking an old implementation also works: https://fisheye6.atlassian.com/browse/~br%3Dsplit-spring/cxf/core/src/main/java/org/apache/cxf/interceptor/LoggingInInterceptor.java?u=3&r=eb4e91ab9d3e29cc1ed35f61848a0a7ae3c917b8 Exception: javax.xml.ws.soap.SOAPFaultException: Unexpected EOF; was expecting a close tag for element at [row,col {unknown-source}]: [1,49152] at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:159) ~[cxf-rt-frontend-jaxws-3.0.0.jar:3.0.0] at com.sun.proxy.$Proxy141.service(Unknown Source) ~[?:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.7.0_51] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[?:1.7.0_51] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.7.0_51] at java.lang.reflect.Method.invoke(Method.java:606) ~[?:1.7.0_51] at org.springframework.expression.spel.support.ReflectiveMethodExecutor.execute(ReflectiveMethodExecutor.java:63) ~[spring-expression-4.0.5.RELEASE.jar:4.0.5.RELEASE] at org.springframework.expression.spel.ast.MethodReference.getValueInternal(MethodReference.java:122) ~[spring-expression-4.0.5.RELEASE.jar:4.0.5.RELEASE] at org.springframework.expression.spel.ast.MethodReference.access$000(MethodReference.java:44) ~[spring-expression-4.0.5.RELEASE.jar:4.0.5.RELEASE] at org.springframework.expression.spel.ast.MethodReference$MethodValueRef.getValue(MethodReference.java:258) ~[spring-expression-4.0.5.RELEASE.jar:4.0.5.RELEASE] at org.springframework.expression.spel.ast.CompoundExpression.getValueInternal(CompoundExpression.java:84) ~[spring-expression-4.0.5.RELEASE.jar:4.0.5.RELEASE] at org.springframework.expression.spel.ast.SpelNodeImpl.getTypedValue(SpelNodeImpl.java:114) ~[spring-expression-4.0.5.RELEASE.jar:4.0.5.RELEASE] at org.springframework.expression.spel.standard.SpelExpression.getValue(SpelExpression.java:111) ~[spring-expression-4.0.5.RELEASE.jar:4.0.5.RELEASE] at org.springframework.integration.util.AbstractExpressionEvaluator.evaluateExpression(AbstractExpressionEvaluator.java:159) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.util.MessagingMethodInvokerHelper.processInternal(MessagingMethodInvokerHelper.java:268) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.util.MessagingMethodInvokerHelper.process(MessagingMethodInvokerHelper.java:142) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.handler.MethodInvokingMessageProcessor.processMessage(MethodInvokingMessageProcessor.java:75) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.handler.ServiceActivatingHandler.handleRequestMessage(ServiceActivatingHandler.java:71) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.handler.AbstractReplyProducingMessageHandler.handleMessageInternal(AbstractReplyProducingMessageHandler.java:170) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.handler.AbstractMessageHandler.handleMessage(AbstractMessageHandler.java:78) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.7.0_51] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[?:1.7.0_51] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.7.0_51] at java.lang.reflect.Method.invoke(Method.java:606) ~[?:1.7.0_51] at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317) ~[spring-aop-4.0.5.RELEASE.jar:4.0.5.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:190) ~[spring-aop-4.0.5.RELEASE.jar:4.0.5.RELEASE] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157) ~[spring-aop-4.0.5.RELEASE.jar:4.0.5.RELEASE] at org.springframework.integration.monitor.SimpleMessageHandlerMetrics.handleMessage(SimpleMessageHandlerMetrics.java:106) ~[spring-integration-jmx-4.0.0.RELEASE.jar:?] at org.springframework.integration.monitor.SimpleMessageHandlerMetrics.invoke(SimpleMessageHandlerMetrics.java:86) ~[spring-integration-jmx-4.0.0.RELEASE.jar:?] at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179) ~[spring-aop-4.0.5.RELEASE.jar:4.0.5.RELEASE] at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:207) ~[spring-aop-4.0.5.RELEASE.jar:4.0.5.RELEASE] at com.sun.proxy.$Proxy93.handleMessage(Unknown Source) ~[?:?] at org.springframework.integration.dispatcher.AbstractDispatcher.tryOptimizedDispatch(AbstractDispatcher.java:116) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.dispatcher.UnicastingDispatcher.doDispatch(UnicastingDispatcher.java:101) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.dispatcher.UnicastingDispatcher.dispatch(UnicastingDispatcher.java:97) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.channel.AbstractSubscribableChannel.doSend(AbstractSubscribableChannel.java:77) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:255) ~[spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:114) [spring-messaging-4.0.3.RELEASE.jar:4.0.3.RELEASE] at org.springframework.messaging.core.GenericMessagingTemplate.doSendAndReceive(GenericMessagingTemplate.java:154) [spring-messaging-4.0.3.RELEASE.jar:4.0.3.RELEASE] at org.springframework.messaging.core.GenericMessagingTemplate.doSendAndReceive(GenericMessagingTemplate.java:44) [spring-messaging-4.0.3.RELEASE.jar:4.0.3.RELEASE] at org.springframework.messaging.core.AbstractMessagingTemplate.sendAndReceive(AbstractMessagingTemplate.java:75) [spring-messaging-4.0.3.RELEASE.jar:4.0.3.RELEASE] at org.springframework.integration.gateway.MessagingGatewaySupport.doSendAndReceive(MessagingGatewaySupport.java:250) [spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.gateway.MessagingGatewaySupport.sendAndReceiveMessage(MessagingGatewaySupport.java:224) [spring-integration-core-4.0.0.RELEASE.jar:?] at org.springframework.integration.ip.tcp.TcpInboundGateway.doOnMessage(TcpInboundGateway.java:99) [spring-integration-ip-4.0.0.RELEASE.jar:?] at org.springframework.integration.ip.tcp.TcpInboundGateway.onMessage(TcpInboundGateway.java:89) [spring-integration-ip-4.0.0.RELEASE.jar:?] at org.springframework.integration.ip.tcp.connection.TcpNioConnection.sendToChannel(TcpNioConnection.java:293) [spring-integration-ip-4.0.0.RELEASE.jar:?] at org.springframework.integration.ip.tcp.connection.TcpNioConnection.run(TcpNioConnection.java:206) [spring-integration-ip-4.0.0.RELEASE.jar:?] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [?:1.7.0_51] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [?:1.7.0_51] at java.lang.Thread.run(Thread.java:744) [?:1.7.0_51] Caused by: com.ctc.wstx.exc.WstxEOFException: Unexpected EOF; was expecting a close tag for element at [row,col {unknown-source}]: [1,49152] at com.ctc.wstx.sr.StreamScanner.throwUnexpectedEOF(StreamScanner.java:685) ~[woodstox-core-asl-4.3.0.jar:4.3.0] at com.ctc.wstx.sr.BasicStreamReader.throwUnexpectedEOF(BasicStreamReader.java:5515) ~[woodstox-core-asl-4.3.0.jar:4.3.0] at com.ctc.wstx.sr.BasicStreamReader.nextFromTree(BasicStreamReader.java:2718) ~[woodstox-core-asl-4.3.0.jar:4.3.0] at com.ctc.wstx.sr.BasicStreamReader.next(BasicStreamReader.java:1069) ~[woodstox-core-asl-4.3.0.jar:4.3.0] at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:766) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:696) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:620) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.interceptor.AbstractLoggingInterceptor.writePayload(AbstractLoggingInterceptor.java:163) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.interceptor.LoggingInInterceptor.logInputStream(LoggingInInterceptor.java:213) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.interceptor.LoggingInInterceptor.logging(LoggingInInterceptor.java:151) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.interceptor.LoggingInInterceptor.handleMessage(LoggingInInterceptor.java:80) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.endpoint.ClientImpl.onMessage(ClientImpl.java:798) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponseInternal(HTTPConduit.java:1636) ~[cxf-rt-transports-http-3.0.0.jar:3.0.0] at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.handleResponse(HTTPConduit.java:1525) ~[cxf-rt-transports-http-3.0.0.jar:3.0.0] at org.apache.cxf.transport.http.HTTPConduit$WrappedOutputStream.close(HTTPConduit.java:1330) ~[cxf-rt-transports-http-3.0.0.jar:3.0.0] at org.apache.cxf.io.CacheAndWriteOutputStream.postClose(CacheAndWriteOutputStream.java:56) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.io.CachedOutputStream.close(CachedOutputStream.java:215) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.transport.AbstractConduit.close(AbstractConduit.java:56) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.transport.http.HTTPConduit.close(HTTPConduit.java:638) ~[cxf-rt-transports-http-3.0.0.jar:3.0.0] at org.apache.cxf.interceptor.MessageSenderInterceptor$MessageSenderEndingInterceptor.handleMessage(MessageSenderInterceptor.java:62) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:514) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:423) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:326) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:279) ~[cxf-core-3.0.0.jar:3.0.0] at org.apache.cxf.frontend.ClientProxy.invokeSync(ClientProxy.java:96) ~[cxf-rt-frontend-simple-3.0.0.jar:3.0.0] at org.apache.cxf.jaxws.JaxWsClientProxy.invoke(JaxWsClientProxy.java:137) ~[cxf-rt-frontend-jaxws-3.0.0.jar:3.0.0] ... 57 more -- This message was sent by Atlassian JIRA (v6.2#6252)