Spring Rest API Monitoring Guide
We may need to track the request and responses for our APIs for different purposes. We can create analytics reports, detect errors, find the slow running endpoints, create activity logs, store audit trails, trigger events based on actions, capture data changes and store them for many other use cases.
Some of the above cases can be also handled with Aspect Oriented Programming but using AOPs heavily adds overhead and impacts the performance. It is generally better idea to separate the logic flow and auditing. Even though tracing the requests can be challenging, once it is implemented our request response flow will not be affected and we can gather useful data.
There are alternative methods depending on the purpose each with pros and cons.
1- Spring Boot Actuator
Actuator comes with a handy http trace filter that stores the requests and response in an in memory repository. In order to use actuator add the dependency:
compile 'org.springframework.boot:spring-boot-starter-actuator'In the applications.yml we need to include httptrace and include the headers we want to store.
management:
endpoints:
web:
exposure:
include: 'httptrace'
trace:
http:
enabled: true
include: AUTHORIZATION_HEADER, COOKIE_HEADERS, PRINCIPAL, REMOTE_ADDRESS, REQUEST_HEADERS, RESPONSE_HEADERS, SESSION_ID, TIME_TAKEN
And now if we go to http://localhost:8080/actuator/httptrace and example trace record looks like as follows:
{
"traces": [
{
"timestamp": "2020-06-14T17:13:42.765476Z",
"principal": {
"name": "admin"
},
"session": null,
"request": {
"method": "GET",
"uri": "http://localhost:8080/api/users?page=0&size=10&sort=id",
"headers": {
"authorization": [
"Bearer token"
],
"sec-fetch-mode": [
"cors"
],
"referer": [
"http://localhost:8081/userList"
],
"sec-fetch-site": [
"same-site"
],
"accept-language": [
"en-GB,en-US;q=0.9,en;q=0.8,ar;q=0.7"
],
"origin": [
"http://localhost:8081"
],
"host": [
"localhost:8080"
],
"connection": [
"keep-alive"
],
"accept-encoding": [
"gzip, deflate, br"
],
"accept": [
"application/json, text/plain, */*"
],
"user-agent": [
"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/83.0.4103.97 Safari/537.36"
],
"sec-fetch-dest": [
"empty"
]
},
"remoteAddress": "0:0:0:0:0:0:0:1"
},
"response": {
"status": 200,
"headers": {
"Access-Control-Expose-Headers": [
"Authorization"
],
"Access-Control-Allow-Origin": [
"*"
],
"Vary": [
"Origin",
"Access-Control-Request-Method",
"Access-Control-Request-Headers"
]
}
},
"timeTaken": 32
}
]
}Quite much of useful data! But it has only the disadvantage of not including the request and response body. The author of the http trace filter suggests implementing your own actuator endpoint if you need to trace the payload requests and responses. You can find a custom actuator endpoint implementation in here.
2- Logging the requests with CommonsRequestLoggingFilter
If you need to only log the requests you can use CommonsRequestLoggingFilter. You can enable it by:
@Bean
public CommonsRequestLoggingFilter logFilter() {
CommonsRequestLoggingFilter filter = new CommonsRequestLoggingFilter();
filter.setIncludeQueryString(true);
filter.setIncludePayload(true);
filter.setMaxPayloadLength(10000);
filter.setIncludeHeaders(true);
filter.setAfterMessagePrefix("REQUEST: ");
return filter;
}And you also need to set the log level as follows:
logging:
level:
org.springframework.web.filter.CommonsRequestLoggin: DEBUGThen it logs requests as follows:
REQUEST: uri=/api/users/current;headers=[host:"localhost:8080", connection:"keep-alive", accept:"application/json, text/plain, */*", authorization:"Bearer token", user-agent:"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/83.0.4103.97 Safari/537.36", origin:"http://localhost:8081", sec-fetch-site:"same-site", sec-fetch-mode:"cors", sec-fetch-dest:"empty", referer:"http://localhost:8081/settings", accept-encoding:"gzip, deflate, br", accept-language:"en-GB,en-US;q=0.9,en;q=0.8,ar;q=0.7"]]The disadvantages of this method:
- It only logs the requests
- For Spring Boot < 2.0 it can not add the request payload.
- It only provides logging, so you need to parse your log files in order to process the data.
3- Implementing your custom http trace filter
The problem with Spring security filters is that the request or response body can be read only once. When you add a filter which reads the payload and after sends the request to other filters in the chain and finally to controller you would get error. And vice versa if you read the response payload from HttpServletResponse before sending it to client, client will receive empty body as the payload can be consumed only once.
To overcome this problem we need to wrap the HttpServletRequest and HttpServletResponse with ContentCachingRequestWrapper and ContentCachingResponseWrapper. By using this wrapper classes we can read the body multiple times.
We can store our data in the following POJO. ContentTrace represents a single record of request and its response.
@Data
@JsonInclude(JsonInclude.Include.NON_NULL)
public class ContentTrace {
public LocalDateTime timestamp;
public long timeTaken;
public int status;
public String method;
public String uri;
public String host;
public String authorization;
public String userAgent;
public String referer;
public String userId;
public String username;
public String remoteAddress;
public String reqBody;
public String resBody;
}And we can simply implement our custom filter as follows:
@Component
public class CustomHttpTraceFilter extends OncePerRequestFilter {
private ContentTrace contentTrace;
private final ContentTraceEventHandler contentTraceEventHandler;
public CustomHttpTraceFilter(ContentTraceEventHandler contentTraceEventHandler) {
this.contentTraceEventHandler = contentTraceEventHandler;
}
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
ContentCachingRequestWrapper requestWrapper = new ContentCachingRequestWrapper(request);
ContentCachingResponseWrapper responseWrapper = new ContentCachingResponseWrapper(response);
contentTrace = new ContentTrace();
contentTrace.setTimestamp(LocalDateTime.now());
try {
filterChain.doFilter(requestWrapper, responseWrapper);
} finally {
afterRequest(requestWrapper, responseWrapper);
}
}
private void afterRequest(ContentCachingRequestWrapper requestWrapper, ContentCachingResponseWrapper responseWrapper) throws IOException {
/*
* From Request Headers
*/
String method = requestWrapper.getMethod();
boolean isGetMethod = method.equals("GET");
// At the moment get requests are not being tracked
if (isGetMethod) {
responseWrapper.copyBodyToResponse();
return;
}
contentTrace.setTimeTaken(System.currentTimeMillis() - contentTrace.timestamp.atZone(ZoneId.systemDefault()).toEpochSecond());
contentTrace.setMethod(method);
contentTrace.setRemoteAddress(requestWrapper.getRemoteAddr());
contentTrace.setUri(requestWrapper.getRequestURI());
contentTrace.setHost(requestWrapper.getHeader("host"));
contentTrace.setAuthorization(requestWrapper.getHeader("authorization"));
contentTrace.setUserAgent(requestWrapper.getHeader("user-agent"));
contentTrace.setReferer(requestWrapper.getHeader("referer"));
contentTrace.setReqBody(getRequestPayload(requestWrapper));
/*
* From Response Headers
*/
contentTrace.setStatus(responseWrapper.getStatusCode());
contentTrace.setResBody(getResponsePayload(responseWrapper));
/*
* Important to copy the original response body, because it is removed.
*/
responseWrapper.copyBodyToResponse();
// publish event
contentTraceEventHandler.publishContentTrace(contentTrace);
}
}It is important to remember to invoke responseWrapper.copyBodyToResponse() method at the end, so that it will put back the payload in the response that will be sent to customer.
We can use the following helper methods to extract the payloads from request and response:
private String getRequestPayload(HttpServletRequest request) {
ContentCachingRequestWrapper wrapper =
WebUtils.getNativeRequest(request, ContentCachingRequestWrapper.class);
if (wrapper != null) {
byte[] buf = wrapper.getContentAsByteArray();
if (buf.length > 0) {
int length = buf.length;
try {
return new String(buf, 0, length, wrapper.getCharacterEncoding());
} catch (UnsupportedEncodingException ex) {
return "[unknown]";
}
}
}
return "";
}
private String getResponsePayload(ContentCachingResponseWrapper wrappedResponse) {
try {
if (wrappedResponse.getContentSize() <= 0) {
return null;
}
return new String(wrappedResponse.getContentAsByteArray(), 0,
wrappedResponse.getContentSize(),
wrappedResponse.getCharacterEncoding());
} catch (UnsupportedEncodingException e) {
logger.error(
"Could not read cached response body: " + e.getMessage());
return null;
}
}So far what we have done is, creating an Spring Security OncePerRequestFilter, it directs the request and after response is received it extracts the headers from response and request and also it extracts the payloads.
Note that we only take a snapshot of the data and this data is being put to a ContentTrace instance. I choose publish and event at this point to not block the request response flow and handle the captured ContentTrace record in another asynchronous block.
Simple implementation for the ContentTraceEventHandler can be as follows:
@Component
public class ContentTraceEventHandler {
private static final Logger logger = LoggerFactory.getLogger(ContentTraceEventHandler.class);
private final ApplicationEventPublisher publisher;
private final UserActivityService userActivityService;
private final ItemEventPublisher itemEventPublisher;
private final UserDetailsServiceImpl userService;
public ContentTraceEventHandler(ApplicationEventPublisher publisher,
UserActivityService userActivityService,
ItemEventPublisher itemEventPublisher,
UserDetailsServiceImpl userService) {
this.publisher = publisher;
this.userActivityService = userActivityService;
this.itemEventPublisher = itemEventPublisher;
this.userService = userService;
}
@Async
@EventListener
public void contentTraceEventListener(ContentTrace contentTrace) {
List <UserActivity> userActivities = UserActivity.fromContentTrace(contentTrace);
if (userActivities != null && userActivities.size() > 0) {
logger.info("Received user activity and saving to the database: {}", userActivities.toString());
userActivityService.saveAll(userActivities);
}
if (userActivities != null &&userActivities.get(0).objectType.equals("item")) {
convertAndPublishItemChangeEvent(userActivities);
}
}
private void convertAndPublishItemChangeEvent(List <UserActivity> userActivities) {
// ..
}
void publishContentTrace(ContentTrace contentTrace) {
logger.debug("Publishing content trace event");
publisher.publishEvent(contentTrace);
}
}This is an example of what we can do with received ContentTrace record. Event Listener works @Async so it handles the received events in a separate thread. Received events are converted to a UserActivity entity and saved to database. And also if the event is related to item module, we can send a changed data notification to our users. So convertAndPublishItemChangeEvent method is showing usage for this purpose.
Another good idea could be publishing these raw records to a Kafka topic and handling each record later on from this topic. If you would like to read about kafka clients please check Kafka posts.