Day: August 6, 2015

Are annotations bad?

I eased off into this topic with my principles on my post about Spring XML vs. Annotations that other day. This easy inlet was also my way of not complicating things too much for my team who is currently involved in writing this new app that will probably have a production life-span for 3-5 years (if we do it right and hope world of technology does not changes over it’s head).

I have been working with Spring Days since 1.1 so yes I have a level of comfort working with very large and complex XMLs. But, I know how to write them and more importantly I know how to read them. Since then Spring has made it easy for developers to understand them – Spring STS with Beans Explorer /Graph. Developers now do not have the need to worry about looking at multiple XML – those tools do the job for them even writing and managing beans for them.

We sacrifice the art of writing good and performant code for the short term gains of improving developer productivity

Since I saw Spring 3.x introduce this notion of Annotation based configurations, and the hype train of using these annotations instead of using XML has been huge for at-least 7 years (if i remember correctly). I have not been able to make peace with this change in direction. Not saying it’s bad, but the point that this feature has been anything but abused by the community to it’s core and Spring has been guilty of promoting the abuse. Any Spring Documentation today, talks about annotation-style’d coding only to follow with the “classic XML way” of doing things.

While people say – it’s easier to read the Code, it’s easier to debug the code with annotations in the mix, they forget what’s it’s not code in code anymore – they have embedded configuration in code. And as far as I remember Configurations were supposed to be externalized. The problem is more severe in cases where we use ORM frameworks like Hibernate and JPA.

Even in original Spring Design, even with XML I feel that how we setup spring applications are not what spring was design for. It’s time for me to go find what Rod Johnson had in his mind when he designed Spring (I know a bit but I need to find some details and get into depth). But thats for another day.

So let’s look at this blog post that explains using JPA with Spring or read this StackOverFlow thread. Well, they both explain how to use, but very soon we realize that but using these so called Rich Annotation based configurations in Code we have diluted the overall meaning of What code/design is supposed to be. This style of programming is great when I have to try something new as a personal pet project to get off the ground quickly – i can just write a class, type a few annotations and boom i am ready to do CRUD, but does this really works in enterprise level applications especially how do we manage this in production.

These articles are nothing but a bunch of marketing/sales pitches that want us to go use these frameworks and new features, but they hardly put in context the complex situations we have to deal with in big production systems

In 2007, we used hibernate extensively on our project (with Spring 2.x with XML based configurations) and we realized very soon that we had taken the ORM framework beyond it’s limits. we had complex queries which we were trying to retrofit into Hibernate and something that was possible to write in MS-SQL as optimized procedures and fire away those queries were now becoming major bottleneck. I was new to the framework but more importantly I had a push from my technical leadership to use Hibernate to it’s fullest. Those people had access to article like I shared earlier and this looked like the way to go but they were nothing but marketing material to sell a feature that Hibernate and ORM brought onto the table. When rubber hits the road is when i had to go back and refactor the code and follow good old ways of writing queries.

90% of the times these frameworks that use annotations work well, but those 10% where you need your system to perform under stress is EXACTLY when these fail

Back tracking to Spring and Annotations now – why i do not like them? Simply because they make me write code like I am a college student who is learning something. They force me away from what used to be good practices in golden old days. Yes it used to take time to setup a few bunch of classes and it used to take time to write the SQL queries but I had right stuff in right places. And Yes it took time before we gathered momentum, but once we had those basics setup tight not only we could development speed, we also had done the things the right ways.

And yes no one can force us, but the average Joe Developer or the average Jim architect do not have the time and inclination and make these POVs, they do a google search and when they see 5 articles saying the same thing, they presume it’s the right thing to do and they proceed happily. And many of our Senior Technologists who also read these articles support the designs and many a times challenge the POV of what I am trying to put here.

TLDR;

Think about it and please do not use annotations to configure your applications. Configurations were never meant to be part of code – the reason they are called configurations. So let’s let those be. A small gain in short term wont go the long way especially when a client asks for a change in a table or a value and you tell him that will beed 5 days of development, testing and deployment.

Making Thread Dumps Intelligent

Long back I had learnt about something called Log MDC, and I was a big fan of it. I was suddenly able to make sense of anything that happens in log files and pin-point to a specific log entry and find what’s right or wrong with it especially when it was about debugging a bug in production.

In 2013 I was commissioned to work on a project that was running through some troubled waters (combination of several things) and almost every week I had to go through several Java Thread Dumps trying to make sense what’s happening in the application to make it stop. Also, there were times when I had to have profilers like AppDynamic, jProfiler, jConsole all hooked up to the application trying to find what’s the issue, and more importantly what’s triggering the issue. jStack was one of the most helpful tools that I had worked with but the thread dumps being bumps had no contextual information that I could work with. I was stuck with seeing 10(s) of dumps with stack traces of what classes are causing the block but there was no information of what’s call and what inputs were causing the issues and it got frustrating very fast. Eventually we found the issues but they were mostly after several rounds of deep debugging the code with variety of data sets.

Once I was done with that project I swore that I will never find myself in that situation again. I Explored ways in which I can use something similar to Log4j’s NDC but have that in threads so that my dumps mean something. And i was able to find that I can change the ThreadName. And my next project I did use that very effectively. I recently came across an article that explains that concept very well. I am not going to rewrite everything they said, so here is a link to their blog post.

So last week I am starting a new project and as I get into coding the framework (using Spring 4.1 and Spring Boot), this is the first class I am writing for the application and ensuring that the filter gets into the code ASAP which not only helps us in post-production but also makes my development logs meaningful.


A copy of the code for both Log4j NDC, and setting up a ThreadName is below.

import java.io.IOException;
import java.text.SimpleDateFormat;
import java.util.Date;
import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.filter.OncePerRequestFilter;
/**
* This is a very Spring opinionated HTTPFilter used for intercepting all requests and decorate the thread name with additional contextual
* information. We have extenced the filter from {@link OncePerRequestFilter} class provided by Spring Framework to ensure that the filter is absolutely
* executd only once per request.
*
* The following information will be added:
* <ul>
* <li>Old Thread name: to ensure that we are not losing any original context with thread names;</li>
* <li>Time when the request was intercepted;</li>
* <li>The RequestURI that proviced information on what RestFUL endpoint was accessed as part of this request;</li>
* <li>A Token that was received in the header. This token is encrypted and does not exposes any confidential information. Also, this token provides
* context which helps during debugging;</li>
* <li>The Payload from the token. This information will be very helpful when we have to debug for issues that may be happening with a call request
* as this holds all the information sent from the called.</li>
* </ul>
*
* This filter will also reset the ThreadName back to it's original name once the processing is complete.
*
* @author Kapil Viren Ahuja
*
*/
public class DecorateThreadNameFilter extends OncePerRequestFilter {
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
throws ServletException, IOException {
final Logger LOGGER = LoggerFactory.getLogger(DecorateThreadNameFilter.class);
final SimpleDateFormat dateFormat = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");
Thread thread = Thread.currentThread();
String threadOriginalName = thread.getName();
String uri = request.getRequestURI();
String time = dateFormat.format(new Date());
String token = request.getHeader("authorization");
try {
thread.setName(String.format("%s StartTime \"%s\" RequestURI \"%s\" Token \"%s\"", threadOriginalName, time, uri, token));
} catch (Exception ex) {
LOGGER.error("Failed to set the thread name.", ex);
// this is an internal filter and an error here should not impact
// the request processing, hence eat the exception
}
try {
filterChain.doFilter(request, response);
} finally {
try {
thread.setName(threadOriginalName);
} catch (Exception ex) {
LOGGER.error("Failed to reset the thread name.", ex);
// this is an internal filter and an error here should not
// impact the request processing, hence eat the exception
}
}
}
}

/**
* Generic filter for intercepting all requests and perform the following generic tasks:
*
* <ul>
* <li>Intercepts the request and then pushed the user domain into the session if one exists.</li>
* <li> Pushes a uniquely generated request identifier to the LOG4J NDC context. This identifier will then be prepended
* to all log messages generated using LOG4J. This allows tracing all log messages generated as part of the same
* request; </li>
* <li> Pushes the HTTP session identifier to the LOG4J NDC context. This identifier will then be prepended to all log
* messages generated using LOG4J. This allows tracing all log messages generated as part of the same HTTP session;
* </li>
* <li> Pushes the IP address of the client to the LOG4J NDC context. The IP address will then be prepended to all log
* messages generated using LOG4J. This allows tying back multiple user sessions initiated with the same logon name to
* be correctly tied back to their actual origins. </li>
* </ul>
*/
public class RequestInterceptorFilter implements Filter
{
/**
* <p>
* <ul>
* <li>Initializes the LOG4J NDC context before executing an HTTP requests.</li>
* <li>Pushes the domain into the session</li>
* </ul>
* </p>
*/
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException
{
HttpServletRequest httpRequest = (HttpServletRequest) request;
if (httpRequest.isRequestedSessionIdFromCookie() && !httpRequest.isRequestedSessionIdValid())
{
// TODO: Need to define an session expiration page and redirect the application to that page
// As of now this is a non-issue as we are handling session expirations on Flex (Front-end) and hence
// no request will come to server in case the session timeout occurs
// HttpServletResponse httpServletResponse = (HttpServletResponse) response;
// httpServletResponse.sendRedirect(httpRequest.getContextPath() + "?expired");
}
else
{
// Create an NDC context string that will be prepended to all log messages written to files.
org.apache.log4j.NDC.push(getContextualInformation(httpRequest));
// Process the chain of filters
chain.doFilter(request, response);
// Clear the NDC context string so that if the thread is reused for another request, a new context string is
// used.
org.apache.log4j.NDC.remove();
}
}
public void init(FilterConfig arg0) throws ServletException
{
}
public void destroy()
{
}
/**
* <p>
* Generates the Contextual information to be put in the log4j's context. This information helps in tracing requests
* </p>
*
* @param httpRequest
* @return
*/
private String getContextualInformation(HttpServletRequest httpRequest)
{
String httpRequestIdentifier = UUID.randomUUID().toString();
String httpSessionIdentifier = httpRequest.getSession().getId();
String clientAddress = httpRequest.getRemoteAddr();
StringBuffer logNDC = new StringBuffer(httpRequestIdentifier + " | " + httpSessionIdentifier + " | " + clientAddress);
String userName = (String)httpRequest.getSession().getAttribute(WebConstants.USERNAME);
if (userName != null)
{
logNDC.append(" | " + userName);
}
String domain = (String)httpRequest.getSession().getAttribute(WebConstants.DOMAIN);
if (domain != null)
{
logNDC.append(" | " + domain);
}
// Create an NDC context string that will be prepended to all log messages written to files.
return logNDC.toString();
}
}