3 ms·
I like the wide log model. At work, we write software that customers run for themselves. When it breaks, we can't exactly ssh in and mutate stuff until it wor
by jrockway 2y ago
I like the wide log model. At work, we write software that customers run for themselves. When it breaks, we can't exactly ssh in and mutate stuff until it works again, so we need some sort of information that they can upload to us. Logs are the easiest way to do that, and because logs are a key part of our product (batch job runner for k8s), we already have infrastructure to store and retrieve logs. (What's built into k8s is sadly inadequate. The logs die when the pod dies.)
Anyway, from this we can get metrics and traces. For traces, we log the start and end of requests, and generate a unique ID at the start. Server logging contexts have the request's ID. Everything that happens for that request gets logged along with the request ID, so you can watch the request transit the system with "rg 453ca13b-aa96-4204-91df-316923f5f9ae" or whatever on an unpacked debug dump, which is rather efficient at moderate scale. For metrics, we just log stats when we know them; if we have some io.Writer that we're writing to, it can log "just wrote 1234 bytes", and then you can post-process that into useful statistics at whatever level of granularity you want ("how fast is the system as a whole sending data on the network?", "how fast is node X sending data on the network?", "how fast is request 453ca13b-aa96-4204-91df-316923f5f9ae sending data to the network?"). This doesn't scale quite as well, as a busy system with small writes is going to write a lot of logs. Our metrics package has per-context.Context aggregation, which cleans this up without requiring any locking across requests like Prometheus does. https://github.com/pachyderm/pachyderm/blob/master/src/internal/meters/meters.go https://github.com/pachyderm/pachyderm/blob/master/src/inter...
Finally, when I get tired of having 43 terminal windows open with a bunch of "less" sessions over the logs, I hacked something together to do a light JSON parse on each line and send the logs to Postgres: https://github.com/pachyderm/pachyderm/blob/master/src/internal/cmd/load-debug-dump-into-postgres/main.go https://github.com/pachyderm/pachyderm/blob/master/src/inter.... It is slow to load a big dump, but the queries are surprisingly fast. My favorite thing to do is the "select * from logs where json->'x-request-id' = '453ca13b-aa96-4204-91df-316923f5f9ae' order by time asc" or whatever. Then I don't have 5 different log files open to watch a single request, it's just all there in my psql window.
As many people will say, this analysis method doesn't scale in the same way as something like Jaeger (which scales by deleting 99% of your data) or Prometheus (which scales by throwing away per-request information), but it does let you drill down as deep as necessary, which is important when you have one customer that had one bad request and you absolutely positively have to fix it.
My TL;DR is that if you're a 3 person team writing some software from scratch this afternoon, "print" is a pretty good observability stack. You can add complexity later. Just capture what you need to debug today, and this will last you a very long time. (I wrote the monitoring system for Google Fiber CPE devices... they just sent us their logs every minute and we did some very simple analysis to feed an alerting system; for everything else, a quick MapReduce or dremel invocation over the raw log lines was more than adequate for anything we needed to figure out.)