CXF Log response time

Question

I use CXF along with JAX-RS to build RESTFul API to provide data for my web applications. I want to know if it is possible to log the time it takes for request X to go to my APIs, be processed and then return as a response.

I've already defined my own CXF logger as JAX-RS features because <cxf:logging /> was a little bit too much. That being said, I know there is a logger for the request logger and there is a response logger. My webapps actually log all of the request / response like this :

11-21 10:37:01,052 INFO  [-8080-exec-7] +- CXF Request  --  ID : [24], Address : [http://my.api.com], HTTP Method : [GET] @org.apache.cxf.interceptor.LoggingOutInterceptor
11-21 10:37:01,089 INFO  [-8080-exec-7] +- CXF Response  --  ID : [24], Response Code : [200]        @org.apache.cxf.interceptor.LoggingInInterceptor

Is there a way I can track the time from the client side and log it?

Answer 1

The thread is an old one but sharing the approach that I took at the client side.

1. We had a SOAP based exchange with a server, so our class extends AbstractSoapInterceptor

2. In handleMessage() we find the direction of the message (inboud or outbound), and calculate the time the processing takes.

---

   public void handleMessage(SoapMessage message) throws Fault {
        try {
            boolean isOutbound = MessageUtils.isOutbound(message);
            if (isOutbound) {
                // outgoing 
                long requestSentTime = System.currentTimeMillis();

            LOGGER.trace("Sending request to server at {} milliseconds", requestSentTime);
            message.getExchange().put(ApplicationConstants.CXF_REQUEST_TIME, requestSentTime);
        } else {
            // incoming
            long requestSentTime = (long) message.getExchange().get(ApplicationConstants.CXF_REQUEST_TIME);
            long requestReceiveTime = System.currentTimeMillis();

            LOGGER.trace("Receiving request from server at {} milliseconds", requestReceiveTime);
            long executionTime = requestReceiveTime - requestSentTime;
            LOGGER.info("Server execution time in milliseconds was {}", executionTime);
        }
    } catch (Exception e) {
        LOGGER.error("handleMessage() threw exception {} ", e);
        // Log and do nothing
    }

}

3. Added the interceptor as in and out interceptor to spring application context xml

---

<bean id="processingTimeInterceptor" class="ProcessingTimeInterceptor" />    
<jaxws:client ...">
        <jaxws:inInterceptors>
            <ref bean="processingTimeInterceptor" />            
        </jaxws:inInterceptors>
        <jaxws:outInterceptors>
            <ref bean="processingTimeInterceptor" />            
        </jaxws:outInterceptors>
    </jaxws:client>