Implementing Elm Event Logging

In my last blog post, I outlined an approach for easy event logging in Elm and then just waved my hands and promised things would work — the rest was just details.

“🤨”, you said.

🤨 indeed, dear reader! “Just details” are two words that can hide such a length of mischief as long as Ireland is wide. You’re right to ask questions and get answers. And so this time we’ll cover — concretely! — how you convert Elm messages to log-ready data and how you get that data from Elm to the your server, complete with examples.

What were we talking about again?

Right, a recap.

We want to record important events as our users use our app: a student watches a video, the robot voice reads the words on the screen aloud, and so on. Tracking these events can drive both product decision-making and technical debugging.

With Elm, the language and framework combine to make the identification and tracking of human-recognizable and important events easy and maintainable. In an Elm app…

1. We define events (messages) with meaningful labels.
2. The data in our application can only update through those meaningful events.
3. With one code change, we can wrap that update with another function to analyze and log every single event as it comes in.

Very simplified, that looks a little like this:

How do Elm Messages Become Log Data?

Good question! There are two approaches you could take, depending on your Elm setup.

Option 1: Debug.toString

The easiest way to turn an Elm object into a string is, of course, just to use Debug.toString.

You can’t use this if you compile your app with Elm 0.19’s --optimize flag. When optimizing, the Elm compiler minifies the message names. Great for asset delivery, bad for a feature that depends on the original human-readable values.

If you’re not running Elm with this flag (for instance, because you want to use Debug.log or you’re using a library like elm-rings to record user sessions for powerful debugging), Debug.toString makes it dead simple to get started:

Simple as this example is, we can already see several of the complications with this approach:

Message constructors with arguments

Dumping a value like “PlayVideo <videoId = 3 >” as-is into your logs is rarely ideal. Data like IDs should be stored as discrete data rather than as part of the event name.

Messages with sensitive information

In any Elm program that deals with passwords, access tokens, or sensitive user data, you’re going to have messages with data you don’t want in your logs. Both Twitter and Github recently announced they’d been accidentally logging passwords in plain text…best not to grow that club.

Spammy Messages

Sometimes our apps have messages that fire a lot. If these represent internal events not useful for analytics (as is often the case) it’s far better not to dump them into an event logging system.

At eSpark, we learned this the hard way. To support students, we added a message that fired every second a student watched a video. Rolling that out to our entire student body without filtering the message accidentally load tested our servers 😅

All three of these problems boil down to “how do we control what data goes to our servers?” — and the answer to that question looks an awful lot to how we log when --optimize is enabled.

Manual Stringification

If you can’t use Debug.toString or you have complex or sensitive messages, you’ll need to manually convert your messages to event data.

This isn’t as bad as it sounds — in fact, it’s actually pretty simple, if a bit repetitive. For each Elm message, we simply pick what we want to log:

As you can see, we log our events with a string event name and then a data blob. If you have different needs, it’s pretty simple to adjust this.

Here at eSpark, we’ve found the slightly extra manual work to account for each message both here and in the update function well worth it. Unlike the all-too-easily-missed manual step required to log events in Javascript, the Elm compiler makes sure we account for every message in our application. (Unless, of course, you throw in a wildcard pattern matcher — I wouldn’t recommend that, though. Far worse than having to add a few lines here is either forgetting to sanitize sensitive user data or accidentally taking your server down with a new spammy message.)

How should we send logs to our server?

Here, similarly, there are (at least) three answers, and which you choose will depend on your needs.

Send individual events through Elm

The most natural way to send these messages up to the cloud is to send an individual log request through Elm for each message. It’s simple (as shown above) and it keeps everything within the warm, safe embrace of the compiler. Logging individual messages through Elm does have two disadvantages, though:

1. It requires one API call per event. Logging quickly became our highest-traffic endpoint.
2. It generates an extra LoggingSuccess message each time you log. If you depend heavily on the Elm debug tools, that gets real annoying real quick.

There are ways to mitigate these issues:

• Build a standalone event logging service that can handle whatever traffic we throw at it. A promising long-term solution but not a quick fix.
• Don’t actually send logging messages in development. Simple, elegant, as long as you don’t mind slightly different behavior.
• Batch up your logging instead of sending individual events.

Send batched events through Elm

Batching multiple events in Elm into a single API call solves both of those problems. If you fire a single message once every, say, 10 seconds, with all the events in that period, you dramatically reduce the load on your server and the noise in your logs. (Each logging request takes slightly longer, of course, but you save on overhead and the number of connections used at any given time.)

Batching event logs together in Elm introduces some additional considerations of its own, though:

• Your model becomes bulkier in order to track data about messages to be logged. Mainly a big deal in development.
• Having events in Elm happen on a timer is more work than in Javascript. Once you master how time works in Elm it’s manageable, but it’s another potentially-new concept to master.
• You need to ensure you can later distinguish which order events in a batch happened in. You can use a client timestamp value, though we chose not to because those can be unreliable. Instead, we preserve the order of the events when posting to the server and slightly increment the timestamp as we log each one.
• Handling the risk of lost events when the user leaves the app. How much work you put into preventing lost events are to you really depends on how important lost events are to you. We decided to tolerate the risk, but if capturing every event is critical, you could persist the data in localStorage to increase the odds you’ll eventually get them. That, though, requires a port and Javascript, which is a lot of complexity.

Here’s an example of this solution:

Send batched events through Javascript

If you don’t mind adding more Javascript to your app to support logging, using JS for batched events can be easier. Javascript makes it easy to handle the timer, to add localStorage support if you want, and keeps duplicative messages out of your Elm debugging console.

The big downside of batched logging in Elm is that you’re using Javascript to do a task that you could do in Elm (at least, if you’re not using localStorage).

Here’s an example of this solution:

In conclusion

The events that happen in our application are tremendously valuable. They let us understand what our users are doing and thus answer both product and debugging questions. They’re also tricky to track, because unlike the kinds of events we can automate, human-level application events generally have required highly fallible manual tracking.

Fortunately, Elm makes that tracking easy — we just have to get through a few implementation details, as we discussed in this blog post.

I hope this has been useful to you! I’d love to hear from you if you try approach out or indeed if you’ve approached logging in Elm some other way.