Filtering Log4j logs for ERRORs with Stacktraces using grep

I have recently been looking for ways to improve the way we collect information from the logs.  We had a process in support where logs produced through log4j would be grep'd for ERROR messages using something like

grep 'ERROR' application.log

This is OK, but it strips any stack trace information present directly below the ERROR log entry and the stack trace will often give you the information you need to go directly to the source of the problem.

After reading the logging documentation from the excellent dropwizard framework, I was inspired to take a slightly different approach.  Dropwizard uses Logback and has some special handling for outputting stack traces that prefixes the lines with the exclamation mark character.  As far as I know this is not possible using Log4j, but it is possible to match on the default formatting for stack trace information.

By default a log4j log file will look something like this


0    [main] INFO  ExceptionThrower  - making progress
1    [main] INFO  ExceptionThrower  - making progress
2    [main] INFO  ExceptionThrower  - making progress
2    [main] ERROR ExceptionThrower  - Something went wrong
java.lang.Exception: Wrapped the exception
at ExceptionThrower.main(ExceptionThrower.java:21)
Caused by: java.lang.NullPointerException: Something was null
at ExceptionThrower.main(ExceptionThrower.java:18)
... 5 more
5    [main] INFO  ExceptionThrower  - making progress
5    [main] INFO  ExceptionThrower  - making progress

Notice that all of the stack trace lines are prefixed with some whitespace then the word "at".  Grepping on the "at" will only give us the stack and not the error message.  But if we use the --before-context parameter to grep then we can pull in the log error message and the details of the exception:

grep -i '^[[:space:]]*at' --before-context=2 application.log

Using this command will give us just the ERROR message, the subsequent stack trace and the stack trace of the causal exception:

2    [main] ERROR ExceptionThrower  - Something went wrong

java.lang.Exception: Wrapped the exception

        at ExceptionThrower.main(ExceptionThrower.java:21)        

Caused by: java.lang.NullPointerException: Something was null

        at ExceptionThrower.main(ExceptionThrower.java:18)

Any other log statements we are not interested in at this time are omitted.

Creating QR Codes for Apache Sling URLs

Matt Cutts mentioned recently that the goo.gl URL shortening service had a trick where if a ".qr" extension is added to the shortened URL then a QR Code image is generated for that URL.

After a quick look at the Apache Sling documentation it seemed that adding such a feature to Sling/ Day CQ would be pretty easy, especially as goo.gl uses the Google Chart API to create the images.

To deal with requests within Sling based on the url extension, a Servlet Service must be added via an OSGi bundle and use service reference properties to detail which extensions/paths/selectors/methods/prefix are handled by this servlet.  Thanks to the maven-bundle-plugin and maven-scr-plugins, packaging this bundle for deployment using Maven is a piece of cake.

The Servlet is quite simple. Here are the SCR annotations from the Servlet class javadoc that tell the Sling what type of requests this Servlet will service:

/**
 * @scr.service interface="javax.servlet.Servlet"
 * @scr.property name="sling.servlet.resourceTypes"
 *               value="sling/servlet/default"
 *
 * @scr.property name="sling.servlet.extensions" value = "qr"
 */

and here are the couple of lines that create the redirect URL for the QR Code image and send that in the response.

private static final String baseUrl = "http://chart.apis.google.com/chart?cht=qr&chs=150x150&choe=UTF-8&chld=H&chl=";
 
protected void doGet(HttpServletRequest req, HttpServletResponse resp) throws ... { 
 resp.sendRedirect(baseUrl + removeQRExtension(req));
} 

protected String removeQRExtension(HttpServletRequest req) {
 StringBuffer url = req.getRequestURL();
 return url.substring(0, url.length() -3);  
} 

Once the OSGi bundle is installed, you can add the .qr extension to any url on your Sling/CQ5 server and get back a QR code for that URL. For example the CQ5 URL
http://localhost:4502/libs/cq/core/content/welcome.html.qr
will give you this QR Code.

Although QR codes not yet made it mainstream, they provide a great way for mobile users to grab information quickly and there seem to be plenty of QR code readers out there.  I have been using QuickMark on the iPhone and that works great for me.

The full code can be found here

http://github.com/cpilsworth/urlqrcode

and the compiled OSGi bundle can be found here

http://github.com/downloads/cpilsworth/urlqrcode/qrcodes-0.0.2-SNAPSHOT.jar

New Google Analytics Tracking Code for CQ 5.x

Today's announcement from Google Analytics that they are providing an alternative page tracking snippet to make tracking asynchronous looks good.  Steve Souders provides a good write up of the benefits of their revised approach.

Fortunately, its very easy to upgrade any Day CQ5.x sites that use the previous incarnation of the Google tracking code from  base page component.

There are 3 steps to updating  the existing Google analytics implementation to an asynchronous one

1. Overlay the analytics.google.jsp in /apps/foundation/components/page/ with an async version
2. Create a script block to queue Google Analytics commands (trackPageView)
3. Add that script block to the section of the base template by overriding head.jsp in the overlayed component

More simply; that is the following 3 files added to the /apps/foundation/components/page/ folder on your CQ instance:

• google.analytics.jsp
• google.analytics.queue.jsp
• head.jsp

This will override the one built into CQ.  If you find that it is not working out for you, then remove these files and you will go back to the original tracking code (make sure you flush any caches here too).

You could always add as an alternative provider for analytics by setting it up as
/libs/foundation/components/page/dialog/items/items/analytics/items/provider/options/google-async
and renaming the files accordingly.  It probably wouldn't hurt to use the provider selection logic in the queue jsp also.  However, it is great to see how easy it is to override out of the box CQ functionality.

Improving Day CQ Performance Using Caching

Recently, we looked at how best to improve performance on one of our CQ4 extranet sites and found that although the page content was being served very fast, a lot of time was being spent by the client downloading various associated resources for that page.  In fact for every page, there were about 40 static resources (png, css, js, etc) that simply didn't change between application releases, yet for every page request the browser would request each of these 40 resources and a 304 Not Modified response returned for each.  Given the fact that each of these requests was laden with SSO, load balancer & CQ session cookies (another problem); the overhead for this was quite great.

In keeping with good practices for speeding up websites, we wanted to set far future Expires headers on these static resources so that once the client populated their cache, there would no more requests for these resources.
The first step towards this was to add some directives to our apache httpd.conf that set the expires headers for us.

This would add an Expires header to each static resource that was requested with a date that was 1 year in the future.

<Location "cq/myapp/static">
ExpiresDefault "access plus 1 year"
</Location>

However, from time to time we make application releases which do change these "static" resources.  For example, any change to the site's CSS design or javascript functionality would need to be represented immediately for users of the site.

To get around this we used the CQ4 mapper functionality to rewrite the resource URLs within the system to include the version number.

This meant changing the /config/delivery/mapper_live_publish.xml file to contain the following mapping:

This adapted the URLs output from CQ templates from
/myapp/static/js/logo.png > /myapp/static/v.1.0.2/js/logo.png

All this means that a client with a populated cache will rarely request any of the static resources of the site unless they change, in which case they are requested immediately.  This saves a tremendous amount of effort for the client browser, and the user experience of the site performance is greatly improved.  These simple steps gave us great performance boost for very little effort.