Remix.run Logo
paragraft 5 hours ago

I've recently come off a team that was racking up a huge Splunk bill with ~70 log events for each request on a high traffic service, and this is all very resonant (except the bit about sampling, I never gave that much thought - reducing our Splunk bill 70x was ambitious enough for me!).

Hadn't heard the "wide event" name, but I had settled on the same idea myself in that time (called them "top-level events" - i.e. we would gather information from the duration of the request and only log it at the "top" of the stack at the end), and evangelised them internally mostly on the basis it gave you fantastic correlation ability.

In theory if you've got a trace id in Splunk you can do correlated queries anyway, but we were working in Spring and forever having issues with losing our MDC after doing cross-thread dispatch and forgetting to copy the MDC thread global across. This wasn't obvious from the top-level, and usually only during an incident would you realise you weren't seeing all the loglines you expected for a given trace. So absent a better solution there, tracking debug info more explicitly was appealing.

Also used these top-level events to store sub-durations (e.g. for calling downstream services, invoking a model etc), and with Splunk if you record not just the length of a sub-process but its absolute start, you can reconstruct a hacky waterfall chart of where time was spent in your query.