RESTFul Service custom request response logging – Jersey?
- Create RESTFul Web Service using Jersey Framework.
- Implement custom request and response logging filter
- Request filter will intercepts the requests coming to RESTFul web service
- Response filter will intercepts the response generated by RESTFul web service.
- Create Application level exception mapper to catch all application exceptions.
Request/Response Logging background & related applications:
Logging is primary requirement for most of web service application. Most of the time, we have a requirement of keeping it as cross cutting concern i.e. typically we want to keep the logging at one place, we do not want to mix the logging with application code.
We have already discussed about Logging of RESTFul Web Service using Spring AOP. In this post, we will achieve the logging of RESTful web service using filters of jersey framework. The application logs will be generated in custom Jersey filter. In our discussion we will create a resource and will write filters to intercept the requests directed REST resource. Also, we will write our ExceptionMapper class to catch application level exceptions. We have used log4j logger libraries to log the requests and responses. We have discussed about the basics of filter in what is filter in enterprise applications.
Custom Logging filter in REST Web service – Jersey framework:
We will implement custom logging filter using ContainerRequestFilter and ContainerResponseFilter. The custom logging filter will implements ContainerRequestFilter and ContainerResponseFilter. The class hierarchy is as shown in Fig 1.
- CustomLoggingFilter will intercepts Request coming to Service
- CustomLoggingFilter will intercepts the response (while sending response back to Client)
 |
| Fig 1: Class Hierarchy of our CustomLoggingFilter |
We will be concerned about implementing the following functions
public void filter(ContainerRequestContext requestContext) throws IOException; public void filter(ContainerRequestContext requestContext, ContainerResponseContext responseContext) throws IOException;
The first method deals with intercepting the requests coming to service and second method is responsible for intercepting the response. To calculate the execution of request we are using MDC (mapped diagnostic context). When requests arrived in service we note down the time of request and while sending the response we will again note down the time. The difference will give us the execution time of method. These kind of features are useful for Audit trialing, Trouble shooting, analysis and profiling of web services.
In CustomLoggingFilter apart from above functions we have following main functions, who are responsible for parsing the incoming request.
logQueryParameters : This function will read the query parameters coming in the HTTP Request and log the parameters.
logMethodAnnotations: This function logs annotations of resource. Generally resource have @GET or @POST or @Produces or @Consumes or @Path annotations, So this method will log all the annotation which the requested resource have.
logRequestHeader: This function read all the headers parameters which HTTP request have and logs the request parameters.
readEntityStream : This function will read the entity stream like in the POST request and log it. We have log this in case of POST request coming to function.
Custom request & response logging filter in RESTFul web service:
package org.learn;
import java.io.ByteArrayInputStream;
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.InputStream;
import java.lang.annotation.Annotation;
import java.util.Iterator;
import java.util.List;
import javax.ws.rs.container.ContainerRequestContext;
import javax.ws.rs.container.ContainerRequestFilter;
import javax.ws.rs.container.ContainerResponseContext;
import javax.ws.rs.container.ContainerResponseFilter;
import javax.ws.rs.container.ResourceInfo;
import javax.ws.rs.core.Context;
import javax.ws.rs.ext.Provider;
import org.glassfish.jersey.message.internal.ReaderWriter;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
@Provider
public class CustomLoggingFilter implements ContainerRequestFilter, ContainerResponseFilter {
@Context
private ResourceInfo resourceInfo;
private static final Logger log = LoggerFactory.getLogger(CustomLoggingFilter.class);
@Override
public void filter(ContainerRequestContext requestContext) throws IOException {
//Note down the start request time...we will use to calculate the total
//execution time
MDC.put("start-time", String.valueOf(System.currentTimeMillis()));
log.debug("Entering in Resource : /{} ", requestContext.getUriInfo().getPath());
log.debug("Method Name : {} ", resourceInfo.getResourceMethod().getName());
log.debug("Class : {} ", resourceInfo.getResourceClass().getCanonicalName());
logQueryParameters(requestContext);
logMethodAnnotations();
logRequestHeader(requestContext);
//log entity stream...
String entity = readEntityStream(requestContext);
if(null != entity && entity.trim().length() > 0) {
log.debug("Entity Stream : {}",entity);
}
}
private void logQueryParameters(ContainerRequestContext requestContext) {
Iterator iterator = requestContext.getUriInfo().getPathParameters().keySet().iterator();
while (iterator.hasNext()) {
String name = iterator.next();
List obj = requestContext.getUriInfo().getPathParameters().get(name);
String value = null;
if(null != obj && obj.size() > 0) {
value = obj.get(0);
}
log.debug("Query Parameter Name: {}, Value :{}", name, value);
}
}
private void logMethodAnnotations() {
Annotation[] annotations = resourceInfo.getResourceMethod().getDeclaredAnnotations();
if (annotations != null && annotations.length > 0) {
log.debug("----Start Annotations of resource ----");
for (Annotation annotation : annotations) {
log.debug(annotation.toString());
}
log.debug("----End Annotations of resource----");
}
}
private void logRequestHeader(ContainerRequestContext requestContext) {
Iterator iterator;
log.debug("----Start Header Section of request ----");
log.debug("Method Type : {}", requestContext.getMethod());
iterator = requestContext.getHeaders().keySet().iterator();
while (iterator.hasNext()) {
String headerName = iterator.next();
String headerValue = requestContext.getHeaderString(headerName);
log.debug("Header Name: {}, Header Value :{} ",headerName, headerValue);
}
log.debug("----End Header Section of request ----");
}
private String readEntityStream(ContainerRequestContext requestContext)
{
ByteArrayOutputStream outStream = new ByteArrayOutputStream();
final InputStream inputStream = requestContext.getEntityStream();
final StringBuilder builder = new StringBuilder();
try
{
ReaderWriter.writeTo(inputStream, outStream);
byte[] requestEntity = outStream.toByteArray();
if (requestEntity.length == 0) {
builder.append("");
} else {
builder.append(new String(requestEntity));
}
requestContext.setEntityStream(new ByteArrayInputStream(requestEntity) );
} catch (IOException ex) {
log.debug("----Exception occurred while reading entity stream :{}",ex.getMessage());
}
return builder.toString();
}
@Override
public void filter(ContainerRequestContext requestContext, ContainerResponseContext responseContext)
throws IOException {
String stTime = MDC.get("start-time");
if(null == stTime || stTime.length() == 0) {
return;
}
long startTime = Long.parseLong(stTime);
long executionTime = System.currentTimeMillis() - startTime;
log.debug("Total request execution time : {} milliseconds",executionTime);
//clear the context on exit
MDC.clear();
}
}
Model Class of RESTFul Web Service – Jersey:
EmployeeModel class is used in resource class of application. We are sending this model class in the form of json or xml to our clients. Similarly client can post json of employee, we accept the employee json in EmployeeModel. Sooner we will take a look into the resource code.
package org.learn;
import javax.xml.bind.annotation.XmlRootElement;
@XmlRootElement (name = "Employee")
public class EmployeeModel {
public String name;
public int age;
public EmployeeModel() {} // JAXB needs this
public EmployeeModel(String name, int age) {
this.name = name;
this.age = age;
}
}
Jersey REST Service exposing GET & POST resources:
ServiceResource:
The resource class exposing our REST interfaces. The code of ServiceResource is as follows.
package org.learn;
import java.util.Date;
import java.util.Random;
import java.util.UUID;
import javax.ws.rs.Consumes;
import javax.ws.rs.GET;
import javax.ws.rs.POST;
import javax.ws.rs.Path;
import javax.ws.rs.PathParam;
import javax.ws.rs.Produces;
import javax.ws.rs.core.MediaType;
import javax.ws.rs.core.Response;
@Path("/service")
public class ServiceResource {
private static final String text = "Message from Server :%s ";
@GET
@Consumes(MediaType.TEXT_PLAIN)
public Response getText() {
String response = String.format(text, new Date());
return Response.status(Response.Status.OK).entity(response).type(MediaType.TEXT_PLAIN).build();
}
@GET
@Path("{name}")
@Consumes(MediaType.TEXT_PLAIN)
public Response getMsg(@PathParam("name") String name) {
String response = String.format(text, name);
return Response.status(Response.Status.OK).entity(response).type(MediaType.TEXT_PLAIN).build();
}
@GET
@Path("/json")
@Produces(MediaType.APPLICATION_JSON)
public EmployeeModel getJson() {
//...........db operation..
//suppose we get these value from database
//............
String randomName = "random" + UUID.randomUUID().toString().substring(0,4);
int randomAge = new Random().nextInt(100);
//returns the value received from database
return new EmployeeModel(randomName,randomAge);
//return new EmployeeModel("Tom", 21);
}
@GET
@Path("/xml")
@Produces(MediaType.APPLICATION_XML)
public EmployeeModel getXml() {
//...........db operation..
//suppose we get these value from database
//............
String randomName = "random" + UUID.randomUUID().toString().substring(0,4);
int randomAge = new Random().nextInt(100);
//returns the value received from database
return new EmployeeModel(randomName,randomAge);
//return new EmployeeModel("Tom", 21);
}
@POST
@Path("/json/object")
@Consumes(MediaType.APPLICATION_JSON)
@Produces(MediaType.APPLICATION_XML)
public EmployeeModel postEmployee(EmployeeModel employee) {
//We receive the object from client
//Client might have send the json string as {"name":"hello","age":"24"}
//do some processing ..save in database
//return the output in xml format....
return employee;
}
@POST
@Path("/json/{name}")
@Produces(MediaType.TEXT_PLAIN)
public Response postPathParamValue(@PathParam("name") String name) {
//Return what ever received from client
String output = "Jersey Says :" + name;
return Response.status(200).entity(output).build();
}
@GET
@Path("/exception")
@Produces(MediaType.TEXT_PLAIN)
public Response throwException() {
throw new RuntimeException("Exception thrown by getPathParamValue resource");
}
}
Request/Response logging filter in RESTFul Service – JAX-RS (Jersey)
We will demonstrate the execution of one GET request and corresponding logs which are getting generated.
We have deployed our application at root context running at 9090 port. So our base application url is “http://localhost:9090/”.
GET Request with http://localhost:9090/service will return the output in text format like
Message from Server :Fri Nov 06 15:15:42 IST 2015
The some of logs will be generated for GET request(for complete logs run the application) :
DEBUG 2015-11-06 15:18:41,239 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] Entering in Resource : /service DEBUG 2015-11-06 15:18:41,241 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] Method Name : getText DEBUG 2015-11-06 15:18:41,241 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] Class : org.learn.ServiceResource DEBUG 2015-11-06 15:18:41,241 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] ----Start Annotations of resource ---- DEBUG 2015-11-06 15:18:41,241 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] @javax.ws.rs.GET() DEBUG 2015-11-06 15:18:41,241 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] ----End Annotations of resource---- DEBUG 2015-11-06 15:18:41,241 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] ----Start Header Section of request ---- DEBUG 2015-11-06 15:18:41,241 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] Method Type : GET DEBUG 2015-11-06 15:18:41,241 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] Header Name: host, Header Value :localhost:9090 DEBUG 2015-11-06 15:18:41,241 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] Header Name: connection, Header Value :keep-alive DEBUG 2015-11-06 15:18:41,242 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] Header Name: cache-control, Header Value :max-age=0 DEBUG 2015-11-06 15:18:41,242 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] ----End Header Section of request ---- DEBUG 2015-11-06 15:18:41,242 org.learn.CustomLoggingFilter [http-apr-9090-exec-6] Total request execution time : 3 milliseconds
Please refer to below link to download the complete code of Jersey logging project. Once, we download the project zip file there we will find ReadMe.md file, which describe the detail of each resource call and logs generated in that particular call.
