how to properly suppress WARNs for webfaults

[maxvar]

The service we provide starts from a cxfendpoint in POJO mode and routes to one of several implementations based on operation called.

We catch SqlExceptions thrown from an ibatis component being used and handle them with onError, preparing custom faults or rethrowing if an SqlException is an unexpected one.

The WS properly responds to a client with faults, but a WARN is also logged for every such fault.

How should we suppress the warnings for our known "custom" faults, still logging warnings for other faults (caused by unhandled exceptions)?

Or do we probably handle them badly in the first place?

The details are below.

We use cxf 2.3.3 and camel 2.6.0.

-

---

The endpoint configured in beans.xml:

<ccxf:cxfEndpoint id="DocsService"

          address="http://$:$/Docs"

          serviceClass="ru.alfastrah.interplat4.docs.Docs" xmlns:ws="http://alfastrah.ru/interplat4/as4sap/docs">

-

---

The part of the route:

from("cxf:bean:DocsService")

     .process(new Processor() {

          @Override

          public void process(Exchange exchange) throws Exception {

               MessageContentsList mcl = exchange.getIn().getBody(MessageContentsList.class);

               exchange.getIn().setBody(mcl.get(0));

          }

     })

     .choice()

          .when(header(CxfConstants.OPERATION_NAME).isEqualTo("GetUnprocessedContractDocumentCards")).to("direct:getUnprocessedContractDocumentCards")

          .when(header(CxfConstants.OPERATION_NAME).isEqualTo("ConfirmContractDocumentCard")).to("direct:ConfirmContractDocumentCard")

          .when(header(CxfConstants.OPERATION_NAME).isEqualTo("ReturnContractDocumentCard")).to("direct:ReturnContractDocumentCard")

     .otherwise().throwException(new Exception("Invalid Operation"));

...

          from("direct:ConfirmContractDocumentCard")

                    .process(new prepParmsForStatusChangeProcessor())

                    .to("ibLanDocs:confirmCard?statementType=Update")

                    .process(new prepResultOfStatusChangeProcessor());

-

---

The handler:

     onException(SQLException.class).handled(true).process(new Processor() {

          @Override

          public void process(Exchange exchange) throws Exception {

               SQLException se = exchange.getProperty(

                         Exchange.EXCEPTION_CAUGHT, SQLException.class);

               if (se.getErrorCode() == 20000) {

                    CardNotFoundException f = new CardNotFoundException();

                    exchange.getOut().setFault(true);

                    exchange.getOut().setBody(f);

               } else if (se.getErrorCode() == 20001) {

                    CardSameStatusFaultBean fb = new CardSameStatusFaultBean();

                    CardSameStatusException f = new CardSameStatusException("some message", fb);

                    exchange.getOut().setFault(true);

                    exchange.getOut().setBody(f);

               } else if (se.getErrorCode() == 20002) {

                    CardArchivedException f = new CardArchivedException();

                    exchange.getOut().setFault(true);

                    exchange.getOut().setBody(f);

               } else {

                    throw se;

               }

          }

     });

-

---

What I get in warnings is:

16:56:10,932 | WARN  | tp1962434640-157 | PhaseInterceptorChain            |  -  -  | Interceptor for DocsService#ConfirmContractDocumentCard has thrown exception, unwinding now

org.apache.cxf.interceptor.Fault: CardSameStatusException

     at org.apache.camel.component.cxf.CxfConsumer$1.checkFailure(CxfConsumer.java:219)[197:org.apache.camel.camel-cxf:2.6.0.fuse-01-09]

     at org.apache.camel.component.cxf.CxfConsumer$1.setResponseBack(CxfConsumer.java:196)[197:org.apache.camel.camel-cxf:2.6.0.fuse-01-09]

     at org.apache.camel.component.cxf.CxfConsumer$1.asyncInvoke(CxfConsumer.java:116)[197:org.apache.camel.camel-cxf:2.6.0.fuse-01-09]

     at org.apache.camel.component.cxf.CxfConsumer$1.invoke(CxfConsumer.java:73)[197:org.apache.camel.camel-cxf:2.6.0.fuse-01-09]

     at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:58)[136:org.apache.cxf.bundle:2.3.3.fuse-01-09]

     at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)[:1.6.0_29]

     at java.util.concurrent.FutureTask$Sync.innerRun(Unknown Source)[:1.6.0_29]

     at java.util.concurrent.FutureTask.run(Unknown Source)[:1.6.0_29]

..22 more...

Caused by: ru.alfastrah.interplat4.docs.CardSameStatusException

     at ru.alfastrah.interplat4.wsdoc.camel.RB$1.process(RB.java:105)[611:ru.alfastrah.interplat4.ws-docs:1.2.0.SNAPSHOT]

     at org.apache.camel.impl.converter.AsyncProcessorTypeConverter$ProcessorToAsyncProcessorBridge.process(AsyncProcessorTypeConverter.java:50)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:70)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:98)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:89)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:70)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:98)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:89)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.interceptor.TraceInterceptor.process(TraceInterceptor.java:99)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:70)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.RedeliveryErrorHandler.processErrorHandler(RedeliveryErrorHandler.java:299)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:208)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.DefaultChannel.process(DefaultChannel.java:269)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

...50 more...

     at org.apache.camel.component.cxf.CxfConsumer$1.asyncInvoke(CxfConsumer.java:97)[197:org.apache.camel.camel-cxf:2.6.0.fuse-01-09]

     ... 27 more

16:56:10,943 | WARN  | tp1962434640-157 | PhaseInterceptorChain            |  -  -  | Interceptor for DocsService#ConfirmContractDocumentCard has thrown exception, unwinding now

org.apache.cxf.interceptor.Fault: CardSameStatusException

     at org.apache.camel.component.cxf.CxfConsumer$1.checkFailure(CxfConsumer.java:219)[197:org.apache.camel.camel-cxf:2.6.0.fuse-01-09]

     at org.apache.camel.component.cxf.CxfConsumer$1.setResponseBack(CxfConsumer.java:196)[197:org.apache.camel.camel-cxf:2.6.0.fuse-01-09]

     at org.apache.camel.component.cxf.CxfConsumer$1.asyncInvoke(CxfConsumer.java:116)[197:org.apache.camel.camel-cxf:2.6.0.fuse-01-09]

     at org.apache.camel.component.cxf.CxfConsumer$1.invoke(CxfConsumer.java:73)[197:org.apache.camel.camel-cxf:2.6.0.fuse-01-09]

     at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:58)[136:org.apache.cxf.bundle:2.3.3.fuse-01-09]

     at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:93)[136:org.apache.cxf.bundle:2.3.3.fuse-01-09]

     at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:255)[136:org.apache.cxf.bundle:2.3.3.fuse-01-09]

     at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:113)[136:org.apache.cxf.bundle:2.3.3.fuse-01-09]

     at org.apache.cxf.transport.http_jetty.JettyHTTPDestination.serviceRequest(JettyHTTPDestination.java:311)[136:org.apache.cxf.bundle:2.3.3.fuse-01-09]

..15 more...

     at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:528)[137:org.eclipse.jetty.util:7.3.1.v20110307]

     at java.lang.Thread.run(Unknown Source)[:1.6.0_29]

Caused by: ru.alfastrah.interplat4.docs.CardSameStatusException

     at ru.alfastrah.interplat4.wsdoc.camel.RB$1.process(RB.java:105)[611:ru.alfastrah.interplat4.ws-docs:1.2.0.SNAPSHOT]

     at org.apache.camel.impl.converter.AsyncProcessorTypeConverter$ProcessorToAsyncProcessorBridge.process(AsyncProcessorTypeConverter.java:50)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:70)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:98)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:89)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.util.AsyncProcessorHelper.process(AsyncProcessorHelper.java:70)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.DelegateAsyncProcessor.processNext(DelegateAsyncProcessor.java:98)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

     at org.apache.camel.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:89)[68:org.apache.camel.camel-core:2.6.0.fuse-01-09]

..70 more...

     at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:117)[143:org.eclipse.jetty.server:7.3.1.v20110307]

     at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:247)[143:org.eclipse.jetty.server:7.3.1.v20110307]

     at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)[143:org.eclipse.jetty.server:7.3.1.v20110307]

     at org.eclipse.jetty.server.Server.handle(Server.java:346)[143:org.eclipse.jetty.server:7.3.1.v20110307]

     at org.eclipse.jetty.server.HttpConnection.handleRequest(HttpConnection.java:581)[143:org.eclipse.jetty.server:7.3.1.v20110307]

     ... 8 more

[njiang]

Hi

The fault was thrown from CXF interceptor chain.

When you throw the fault, the CXF interceptor will write a WARN.

If you don't want that , you can consider to configure the log leave of CXF and change the code of org.apache.camel.component.cxf.CxfConsumer$1.checkFailure to log the fault that you want.

Willem

[davsclaus]

Hi

I actually agree with you and see this as a valid use-case to have CXF return Soap Faults, as well as regular Saop responses. And that CXF should not make such a noise by default. If the Soap Fault has been defined in the WSDL contract, then its a valid response.

I logged a ticket to improve this, so at least its easier to configure the logging level.

http://fusesource.com/issues/browse/SF-396

[njiang]

I just went though the code of PhaseInterceptorChain and you can suppress the WARNs by change the log level of the PhaseInterceptorChain to ERROR like this

log4j.logger.org.apache.cxf.phase.PhaseInterceptorChain=ERROR

Willem