At Hurricane Labs, we love logs and we love video games. Any chance to combine the two is exciting, and recently I stumbled on just such an opportunity.
My friends and I have been hooked on 7 Days to Die, a survival horror game in which players scavenge an apocalypse-ridden world and build a defense to survive a massive zombie horde that attacks every seven days. One of my friends had found an item–a book, specifically–that would’ve been a significant upgrade for another player, but when they met up to exchange the item it had disappeared. We dismissed it as a glitch, but I began to wonder–did the game have logs, and could they help us discover what had happened? Naturally, my weapon of choice was Splunk.
Unexpected bonus: server-side logs
Server-side logs are actually pretty rare in the gaming world these days. The concept of hosting a local server is antiquated, replaced by online servers hosted by game companies themselves. 7 Days to Die, however, allows players to operate their own server and configure it however they’d like. We didn’t realize this at first–my brother was the first one to start the game and we all joined him, unaware that we were actually joining a server running locally on his computer, which also happened to be the one with the least amount of resources. Eventually he sent me the server files and I started hosting from mine.
I was pleasantly surprised by the logs that had been generated. Every log starts with a consistent and readable timestamp and a generally uniform message format. For example:
Scrolling through the unexpectedly large file, I noticed that in addition to operational logs, there were logs about player behavior and AI behavior: kills, deaths and even how many zombies were spawned! It was time to get these log files into Splunk and really start digging in.
I chose to use
7daystodie:output as the custom sourcetype name to reflect both the software and the log file name (output_log) in case there is ever another log filetype we want to ingest.
The first thing I noticed is that every log file begins with a header that has interesting information but isn’t something we want to index every time:
To omit this, I took advantage of the
FIELD_HEADER_REGEX props setting. This uses Regular Expression to identify the last line of the header and in this case tells Splunk not to index anything above it:
Line-breaking and timestamp parsing was the next objective. Fortunately, it uses a pretty standard and consistent timestamp, which is already more than I can say for some other more common data sources. When I first loaded this into the data preview through the web interface, Splunk actually did a good job identifying and separating events without any further configuration. The best practice though is to be as specific as possible here to avoid any potential issues now or in the future.
At Hurricane Labs we like to cover at least
TIMEZONE. Between these settings, we’ve specified where in the log the timestamp occurs, how far from that point to consider part of the timestamp, what the timestamp looks like, and what timezone the log was written in. We also prefer to have control over the event line-breaking, in other words specifying what constitutes a single event. In most cases, such as ours, the event in the log begins with a timestamp so we’ve told Splunk not to line merge automatically and we specify our own condition in the
As you’ll recall from the brief example above, our timestamp looks like this:
Our props configuration so far is:
So, what happened to that book?
I ingested a single log file to a test index to make sure everything behaved as expected and started playing with the data to see what was available. Splunk automatically extracted some fields that were already key=value pairs, but some more specific field extractions were necessary. I had data about when players connected and disconnected, how long their session was, how many zombies (and what types) they killed, and if they died. I also had some internal system messages such as audio files failing to load, no space to load in a resource, and–most relevant to our original goal of discovering the fate of our missing item–when a resource “fell off the world.”
Some examples of the field extractions:
If you’re not familiar with reading Regular Expression one of the above extractions pulls out the priority: INF (informational) or WRN (warning). Narrowing down on the warning messages I began to see events such as:
“Fell off the world” is an interesting fate for an item, but the game is technically in early access (meaning it is still being worked on). Honestly, open world survival games usually have bugs similar to these simply due to the scope of the environment and the resources, so you kind of know what you’re getting into. But is it what happened to our item, a book that would’ve taught a much-needed skill for one of our players?
The log above involves
resourceScrapIron, which as you can probably guess is not the book in question. But with that name extracted, we can easily perform an all-time search for the “fell off” warning message and display all the different items that have been logged: