Details
-
Bug
-
Resolution: Done
-
Major
-
jboss-fuse-6.0
-
None
-
None
-
%
Description
Hi,
We have a test case that is a simple proxy with both inbound and outbound CXF endpoints. The inbound endpoint isn't expecting a security header, however does have a WSS4JOUt Interceptor and should add the security header to the outbound request. If the inbound request contains a security header we go into some sort of loop and the container runs out of memory.
Jim Minter ran the test case through the debugger:
"qtp967241364-210" prio=10 tid=0x00007f1de4306800 nid=0x1c9f runnable [0x00007f1d8d451000] java.lang.Thread.State: RUNNABLE at org.apache.cxf.staxutils.W3CDOMStreamWriter.writeCharacters(W3CDOMStreamWriter.java:292) at org.apache.cxf.staxutils.DelegatingXMLStreamWriter.writeCharacters(DelegatingXMLStreamWriter.java:91) at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:588) at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:564) at org.apache.cxf.staxutils.StaxUtils.copy(StaxUtils.java:542) at org.apache.cxf.binding.soap.interceptor.SoapOutInterceptor.writeSoapEnvelopeStart(SoapOutInterceptor.java:160) at org.apache.cxf.binding.soap.interceptor.SoapOutInterceptor.handleMessage(SoapOutInterceptor.java:81) at org.apache.cxf.binding.soap.interceptor.SoapOutInterceptor.handleMessage(SoapOutInterceptor.java:61) at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:262) - locked <0x00000000e28af4a0> (a org.apache.cxf.phase.PhaseInterceptorChain) at org.apache.cxf.endpoint.ClientImpl.doInvoke(ClientImpl.java:530) at org.apache.cxf.endpoint.ClientImpl.invoke(ClientImpl.java:456) at org.apache.camel.component.cxf.CxfProducer.process(CxfProducer.java:112) at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) at org.apache.camel.processor.SendProcessor$2.doInAsyncProducer(SendProcessor.java:122) at org.apache.camel.impl.ProducerCache.doInAsyncProducer(ProducerCache.java:298) at org.apache.camel.processor.SendProcessor.process(SendProcessor.java:117) at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99) at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:73) at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99) at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) at org.apache.camel.processor.interceptor.TraceInterceptor.process(TraceInterceptor.java:91) at org.apache.camel.processor.interceptor.HandleFaultInterceptor.process(HandleFaultInterceptor.java:41) at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99) at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99) at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) at org.apache.camel.fabric.FabricTraceProcessor.process(FabricTraceProcessor.java:81) at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99) at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:334) at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:220) at org.apache.camel.processor.interceptor.StreamCachingInterceptor.process(StreamCachingInterceptor.java:52) at org.apache.camel.processor.RouteContextProcessor.processNext(RouteContextProcessor.java:46) at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) at org.apache.camel.processor.interceptor.DefaultChannel.process(DefaultChannel.java:308) at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) at org.apache.camel.processor.Pipeline.process(Pipeline.java:117) at org.apache.camel.processor.Pipeline.process(Pipeline.java:80) at org.apache.camel.processor.RouteContextProcessor.processNext(RouteContextProcessor.java:46) at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) at org.apache.camel.processor.UnitOfWorkProcessor.processAsync(UnitOfWorkProcessor.java:150) at org.apache.camel.processor.UnitOfWorkProcessor.process(UnitOfWorkProcessor.java:117) at org.apache.camel.processor.RouteInflightRepositoryProcessor.processNext(RouteInflightRepositoryProcessor.java:48) at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:73) at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:99) at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:90) at org.apache.camel.management.InstrumentationProcessor.process(InstrumentationProcessor.java:73) at org.apache.camel.component.cxf.CxfConsumer$1.asyncInvoke(CxfConsumer.java:93) - locked <0x00000000e2533d18> (a org.apache.cxf.transport.http_jetty.continuations.JettyContinuationWrapper) at org.apache.camel.component.cxf.CxfConsumer$1.invoke(CxfConsumer.java:72) at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:58) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at org.apache.cxf.workqueue.SynchronousExecutor.execute(SynchronousExecutor.java:37) at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:107) - locked <0x00000000e28af958> (a org.apache.cxf.interceptor.ServiceInvokerInterceptor$2) at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:262) - locked <0x00000000e26edb48> (a org.apache.cxf.phase.PhaseInterceptorChain) at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:236) at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:214) at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:194) at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:130) at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:221) at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPost(AbstractHTTPServlet.java:141) at javax.servlet.http.HttpServlet.service(HttpServlet.java:713) at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:197) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at org.ops4j.pax.web.service.internal.HttpServiceStarted$1.invoke(HttpServiceStarted.java:182) at org.ops4j.pax.web.service.internal.$Proxy6.service(Unknown Source) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:652) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:447) at org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:70) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137) at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:534) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:227) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1038) at org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:117) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:374) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:189) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:972) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135) at org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:75) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116) at org.eclipse.jetty.server.Server.handle(Server.java:363) at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:483) at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:931) at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:992) at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:856) at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235) at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82) at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:627) at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:51) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) at java.lang.Thread.run(Thread.java:724)
By stepping through, what he has seen is, when going from SoapOutInterceptor.writeSoapEnvelopeStart to StaxUtils.copy, the source XML tree ("node") looks well-formed. As the copy goes on, it successfully iterates down the wsse:Security, wsu:Timestamp, wsu:Created tags until it hits the timestamp TextImpl element (e.g. 2013-08-22T10:23:03.044Z). Entering the copy loop for the first time, that source TextImpl element correctly has nextSibling set to null. However, after the copy of that element takes place the /source/ nextSibling field is changed, I believe incorrectly. I'm guessing that this is happening because the source and the destination are incorrectly aliased in some way. The copy then follows nextSibling and enters a loop. I believe that this loop doesn't terminate, and also causes successive concatenations of the timestamp in memory, hence the 100% CPU usage and eventual memory exhaustion. Certainly it doesn't appear that the thread's execution ever proceeds beyond StaxUtils.copy(). It would also explain why this problem is not seen when there are no nodes in the soapenv:Header.
I also ran the test case and dumped the took a heap dump. Offending class stack attached in screenshot.
