Skip to main content

Being Analytics driven vs firefight driven

We have doubled our incoming traffic every 6 months and past 3 years have always been in firefighting mode where some customer reports an issue or a node goes down and we try to analyze the root cause and fix them.

Lately I am trying to move away from working in a firefight driven mode to Analytics driven mode. What I meant is being proactive to monitor and understand the system by gathering various metrics and fixing issues before cusotmer notices them. For e.g. to put our nodes in HA mode I had to store a sessionId to userId mapping in database, the only real reason to do this was for our Flash file uploader because it makes a request but doesnt pass the sessionId in cookie but it passes as request parameter. This causes the request to go to a completely different node.  So to handle this we wrote a session listener that would save the sessionId to userId mapping in db.  The code went live and suddenly after some days the db went down. What happened was that the developer forgot to remove the row in session purge and the table had grown to 140M.  I didnt expected this table to be more than 1-2M at a time but due to code bug this issue occurred.  So first thing I did was to add a monitor on all tables in our transient db and it alerts me if any table has >10M rows. Immediately it caught another code bug where an audit table has grown to >70M for one customer so we caught it and fixed it in hotpatch it without causing another downtime.

Another incident happened two weeks back when I travelled to Bay area and for two days a db went down exactly between 11:30 and 11:45 and restarted on its own.  What we found that again that session table was 20M even after adding the session destroy delete fix and a backend purge job from all nodes were trying to delete 18M records out of this 20M table.  What happened was that some code flows(webdav and FTP upload) that are not supposed to be session dependent were setting user in session.  Users uploaded 20M files using FTP/webdav and that caused this table to ballon. The only reason I was able to find the issue was because I log stats on each node as to what methods happened every 5 mins. So I grepped queries in those between 11:30 and 11:45 on all nodes.

Immediately I realized that I need something more global, we have 40 mysql servers and I needed some report as to how many queries are happening on each node and in overall at DC level.  If I had this report then I woudl have caught the session thing before it became an issue.  Scribe comes to rescue, now I write those 5 min stats to scribe that gets aggregated in central scribe across all datacentres. I roll the log nightly and wrote a python cron to generate report that dumps queries and no of times they happened  and their avg time.

Yesterday it went live in UAT and immediately I found 2-3 issues where top queries were not what we expected (caching bug :)). Lesson learnt is be analytics driven rather than hunch or firefight driven.


Popular posts from this blog

RabbitMQ java clients for beginners

Here is a sample of a consumer and producer example for RabbitMQ. The steps are
Download ErlangDownload Rabbit MQ ServerDownload Rabbit MQ Java client jarsCompile and run the below two class and you are done.
This sample create a Durable Exchange, Queue and a Message. You will have to start the consumer first before you start the for the first time.

For more information on AMQP, Exchanges, Queues, read this excellent tutorial
import com.rabbitmq.client.Connection; import com.rabbitmq.client.Channel; import com.rabbitmq.client.*; public class RabbitMQProducer { public static void main(String []args) throws Exception { ConnectionFactory factory = new ConnectionFactory(); factory.setUsername("guest"); factory.setPassword("guest"); factory.setVirtualHost("/"); factory.setHost(""); factory.setPort(5672); Conne…

Logging to Graphite monitoring tool from java

We use Graphite as a tool for monitoring some stats and watch trends. A requirement is to monitor impact of new releases as build is deployed to app nodes to see if things like
1) Has the memcache usage increased.
2) Has the no of Java exceptions went up.
3) Is the app using more tomcat threads.
Here is a screenshot

We changed the installer to log a deploy event when a new build is deployed. I wrote a simple spring bean to log graphite events using java. Logging to graphite is easy, all you need to do is open a socket and send lines of events.
import org.slf4j.Logger;import org.slf4j.LoggerFactory; import; import; import; import java.util.HashMap; import java.util.Map; public class GraphiteLogger { private static final Logger logger = LoggerFactory.getLogger(GraphiteLogger.class); private String graphiteHost; private int graphitePort; public String getGraphiteHost() { return graphiteHost; } public void setGraphite…

What a rocky start to labor day weekend

Woke up by earthquake at 7:00 AM in morning and then couldn't get to sleep. I took a bath, made my tea and started checking emails and saw that after last night deployment three storage node out of 100s of nodes were running into Full GC. What was special about the 3 nodes was that each one was in a different Data centre but it was named same app02.  This got me curious I asked the node to be taken out of rotation and take a heap dump.  Yesterday night a new release has happened and I had upgraded spymemcached library version as new relic now natively supports instrumentation on it so it was a suspect. And the hunch was a bullseye, the heap dump clearly showed it taking 1.3G and full GCs were taking 6 sec but not claiming anything.

I have a quartz job in each jvm that takes a thread dump every 5 minutes and saves last 300 of them, checking few of them quickly showed a common thread among all 3 data centres. It seems there was a long running job that was trying to replicate pending…