Splunking the Zombie Apocalypse – Security Boulevard

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 itema book, specificallythat wouldve 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 wonderdid the game have logs, and could they help us discover what had happened? Naturally, my weapon of choice was Splunk.

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 theyd like. We didnt realize this at firstmy 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:

Copy to Clipboard

2021-01-20T23:31:49 14350.539 INF GMSG: Player xAweSamx left the game

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 isnt something we want to index every time:

Copy to Clipboard

Mono path[0] = D:/SteamLibrary/steamapps/common/7 Days To Die/7daystodie_Data/ManagedMono config path = D:/SteamLibrary/steamapps/common/7 Days To Die/MonoBleedingEdge/etcInitialize engine version: 2019.2.17f1 (8e603399ca02)[XR] Discovering subsystems at path D:/SteamLibrary/steamapps/common/7 Days To Die/7daystodie_Data/UnitySubsystemsForcing GfxDevice: Direct3D 11GfxDevice: creating device client; threaded=1Direct3D:Version: Direct3D 11.0 [level 11.1] Renderer: NVIDIA GeForce RTX 2070 SUPER (ID=0x1e84)Vendor:VRAM: 8011 MBDriver: 27.21.14.6079Begin MonoManager ReloadAssembly Completed reload, in 2.962 seconds Initializing input.

Input initialized.

Initialized touch support.

UnloadTime: 6.034400 ms

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:

Copy to Clipboard

[7daystodie:output]FIELD_HEADER_REGEX = UnloadTime

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 TIME_PREFIX, TIME_FORMAT, MAX_TIMESTAMP_LOOKAHEAD, and TIMEZONE. Between these settings, weve 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 weve told Splunk not to line merge automatically and we specify our own condition in the LINE_BREAKER setting.

As youll recall from the brief example above, our timestamp looks like this:

Copy to Clipboard

2021-01-20T23:31:49

Our props configuration so far is:

Copy to Clipboard

[7daystodie:output]FIELD_HEADER_REGEX = UnloadTimeLINE_BREAKER = ([rn]+)d{4}-d{2}-d{2}Td{2}:d{2}:d{2}MAX_TIMESTAMP_LOOKAHEAD = 19SHOULD_LINEMERGE = falseTIMEZONE = US/EasternTIME_FORMAT = %Y-%m-%dT%H:%M:%STIME_PREFIX = ^

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, andmost relevant to our original goal of discovering the fate of our missing itemwhen a resource fell off the world.

Some examples of the field extractions:

Copy to Clipboard

EXTRACT-playerinfo = INFs+Players+(?.+?)s+disconnecteds+afters+(?d+.d+)s+minutesEXTRACT-spawnerinfo = INFs+(?S+)s+spawneds+(?S+)EXTRACT-vendorprio = d{4}-d{2}-d{2}Td{2}:d{2}:d{2}s+d+.d+s+(?S+)s+EXTRACT-killerinfo = Entitys+(?S+)s+d+s+killeds+bys+(?S+)s+EXTRACT-component = d{4}-d{2}-d{2}Td{2}:d{2}:d{2}s+d+.d+s+WRNs+(?NosS+|D+?)s+

If youre 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:

Copy to Clipboard

2021-01-24T22:36:46 8357.174 WRN Entity [type=EntityItem, name=resourceScrapIron, cnt=150] fell off the world, id=51777 pos=(1327.2, -0.5, 108.7)

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 youre getting into. But is it what happened to our item, a book that wouldve 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:

Continued here:
Splunking the Zombie Apocalypse - Security Boulevard