1012509 - mozsvc: metlog out, heka in

Status: VERIFIED FIXED

(Cloud Services :: Server: Core, defect)

Description

[Ryan Kelly [:rfkelly]]

We seem to have settled on a particular logging pattern for our production servers, so we should update mozsvc to match it:

  * write application logs into a file in JSON format
  * slurp this file with heka and send it into the void^W^W our monitoring infra
  * log a request-summary line with various timers and counters at the completion of each request

The bottom line is, we can yank the metlog stuff and go for something a lot simpler.  I think it will end up working OK with just stdlib logging infra plus some simple timers.

Corresponding syncstorage bug: Bug 969185
Corresponding tokenserver bug: Bug 969184

Do we have any other consumers of mozsvc at this stage, which could be affected by API changes here?

Comment 1

[Rob Miller [:rmiller]]

\o/!

Comment 2

[Ryan Kelly [:rfkelly]]

Attachment: mozsvc-json-log-formatter.diff

Part 1 is to add a JSON log formatter compatible with the stdlib logging infra.  The formatting here is based on similar recent work in the fxa verifier codebase: https://github.com/mozilla/browserid-verifier/blob/master/lib/log/json.js

Comment 3

[Ryan Kelly [:rfkelly]]

Attachment: mozsvc-metrics.diff

For Part 2, we use stdlib logging everywhere and replace all the metlog stuff in mozsvc.metrics some a simple "dict that you can stuff things into" approach.  I'm going to attach this file raw as a separate attachment so it's easier to review, as it's basically rewritten.

Comment 4

[Ryan Kelly [:rfkelly]]

Attachment: metrics.py

Attaching the metrics.py file for easier review.  This is identical to what's in that file in the previous diff-based attached.

I've deliberately been pretty brutal here, paring down from the metlog functionality to just the core of what we need.  Each request gets a "request.metrics" dict into which you can stuff things during request processing, and its contents are emitted in a summary log line at the end.  There are some helpers to make the stuffing of things into this dict a little simpler, but that's it.

This puts the logging/metrics infra in mozsvc on a par with what we're using in the prod fxa codebases - nothing more powerful, but also nothing more complicated.

Rob, I've pinged you for review here so you can tell me about all the things I missed that metlog was actually taking care of automatically.  I could easily have gone too far here :-)

Comment 5

[Rob Miller [:rmiller]]

Comment on attachment 8425258 [details] [diff] [review]
mozsvc-metrics.diff

Review of attachment 8425258 [details] [diff] [review]:
-----------------------------------------------------------------

::: mozsvc/metrics.py
@@ +60,3 @@
>  
> +    The log message and any default values for the metrics dict can be
> +    specified at decoator creation time.

Typo.

Comment 6

[Rob Miller [:rmiller]]

Comment on attachment 8425263 [details]
metrics.py

In `initialize_request_metrics`, you only use `xff` if `request.remote_addr` has a value. You should either unindent `request.metrics["remoteAddressChain"] = xff` so it's always set, or you should move the `xff` calculation code into the if clause so you don't ever waste time calculating the `xff` value only to throw it away.

Comment 7

[Toby Elliott [:telliott]]

Comment on attachment 8425256 [details] [diff] [review]
mozsvc-json-log-formatter.diff

Review of attachment 8425256 [details] [diff] [review]:
-----------------------------------------------------------------

all good, with the irc note about the confusing comment.

Comment 8

[Ryan Kelly [:rfkelly]]

Attachment: mozsvc-metrics.diff

Sorry :RaFromBRC, attachment upload fail on my part gave you an old version of the diff.  Attaching a new one.  The previously-uploaded metrics.py was the correct version, the rest of this diff is changed (and free of at least one typo, thanks for catching).

Comment 9

[Ryan Kelly [:rfkelly]]

Part 1: https://github.com/mozilla-services/mozservices/commit/83a2b79c317bdefae97c225eb955841e264014c2
Part 2: https://github.com/mozilla-services/mozservices/commit/8747025622b772ff646aaa8ce691b78a5a78d7b8

Comment 10

[James Bonacci [:jbonacci]]

Verified in code.