Event logging in Rails
Event logging provides tremendous business value and has many downstream applications. For example, if we just look at login attempts, both successful and failed, we can do several things: automatically send a password reset email after 3 consecutive failed log in attempts to avoid losing a user, detect and block brute force attacks, analyze differences in platform specific behaviors, etc. These user experience, security, and data analysis applications extend beyond login attempts to almost every high level event our API is capturing. There is probably somebody (a service) somewhere (in our stack) that cares about each API event either individually or in the context of others.
Event logging has the benefit of separating the “producers” of data from the “consumers” of data, and allowing each to perform individually. For example, you most certainly don’t want a real-time anomaly detection service running synchronously in your API. A first step might be to throw a resque background job at the problem. But then you’ll soon realize that you’re doing the same thing over and over for each new type of service you need, and that each service might need the same data as other services.
Enter Kafka. I’ve been a huge fan of Kafka ever since reading Jay Kreps’ The Log. The short of Kafka is that it allows you to have different and disparate producers and consumers of data/events, and separate the logic into services to meet your needs. The best part is that producers don’t need to know about each other, inform each other of their existence, or coordinate beyond agreeing on data transport. Producers just produce data (throw it at Kafka) and consumers just consume data (read it from Kafka).
I wanted to add a naive Kafka event-logging service to my Rails app. I had a couple of self-imposed requirements to make the service easy to use and avoid cluttering my code.
- Logging must be encapsulated and easy to change what’s under the hood.
- Events should have some standardized format, but also encapsulated enough to change them around when necessary.
- It should be very easy to add new event types.
- It takes a single line of code to log an event — this wasn’t a strict requirement but I really didn’t want to litter my API with a ton of lines (more than 1) of logging code.
After a few hours and a couple iterations I came up with something that I was generally pretty happy with, knew fit my needs right now, and pushed it to production. Below is a simplified version, removing clutter such as experiment groups, etc.
I created a base Event class that contained all of the common code/setup for each event, an event class for each event type — LoginEvent for example, and an EventLogger class for actually logging events.
The above shows an example event, this one being an event for login attempts. The Event class uses the event_type method in order to nicely structure the payload, simply adding an event_type field. The topic method is used by the EventLogger to decide which topic to write to (admittedly I’m least happy about this mixing of concerns). Finally the payload method provides the data that will ultimately be logged to Kafka.
Adding this to our SessionController, we might do something like,
The final piece to this setup is the actual EventLogger. The nice thing is that the API doesn’t really care what the event logger does, as long as it’s not blocking. Without Kafka, you might just do some simple statsd logging, or even write to a local file for later manual inspection and analysis.
Here we have a single method that calls out Kafka producer with the appropriate topic and payload.
It is really easy to begin logging with this setup in place. We only have two steps: First create a new event class for the new event to be logged, then log that event from the API. The nice part is that each event fully own’s its payload function and has the ability to log whatever information it wants. Moreover the logger is fully encapsulated and we, as in the API, don’t need to worry what’s actually happening under the hood.
