1212925 - structured logging library

Status: RESOLVED FIXED

(Taskcluster :: Services, defect)

Description

[John Ford [:jhford] CET/CEST Berlin Time]

We should have structured logging in our components for lots of reasons, including alerting and talking to security aggregation systems.

This should be implemented as a library which components can use.  There must be an easy transition path for components using the debug module.

Comment 1

[John Ford [:jhford] CET/CEST Berlin Time]

https://github.com/taskcluster/taskcluster-logging is where I'm working, on the master branch.

Comment 2

[John Ford [:jhford] CET/CEST Berlin Time]

Attachment: sample to use debug compatibility for aws provisioner

This is the patch required to move the aws provisioner to using bunyan without the nice structured logging bits.  Please let me know what you think!

Comment 3

[Greg Arndt [:garndt]]

Is there a reason why this is call it debugCompat rather than just debug?

Comment 4

[John Ford [:jhford] CET/CEST Berlin Time]

oh, and the log.js file is:

module.exports = require('taskcluster-logging')({name: 'aws-provisioner'});

Comment 5

[John Ford [:jhford] CET/CEST Berlin Time]

(In reply to Greg Arndt [:garndt] from comment #3)
> Is there a reason why this is call it debugCompat rather than just debug?

yes, because then we'd be overwriting the .debug method (in the .info, .warn, .fatal, .error, and .trace family).  Then we'd be unable to log debug messages.

Comment 6

[John Ford [:jhford] CET/CEST Berlin Time]

so to be clear, debugCompat is called once to return a debug function, not the call you have to make each time you want to interface with the old debug module.

Comment 7

[Greg Arndt [:garndt]]

ah I see, thanks for clearing that up for me.

Comment 8

[Greg Arndt [:garndt]]

Looks like this would be simple enough to convert where we're using debug.  nice!

Comment 9

[Jonas Finnemann Jensen (:jonasfj)]

@jhford,
So basically I would be allowed to do the following:
  let log = require('../lib/log');
  let debug = log.debugCompat("...");

  // In my code
  log.info("la lal al al ");
  log.error({what: "bad-thing", why: "who knows?", blame: "any one but me"});
  debug("la la la"); // legacy debug statement

That seems nice...

@jhford, can we rename taskcluster-logging to taskcluster-lib-log or something like that.

More importantly, how does this work with modules?
Ie. I have cases where base.API logs something, how does it do that?
What if they use different versions of the logging library? (perhaps even different bunyan versions?)

@jhford, ^ I think that is my last concern, do I give base.API an instance of log from my app or?

Comment 10

[Jonas Finnemann Jensen (:jonasfj)]

FYI, I don't mind the horrible name debugCompat, it encourages us to move on :)

Comment 11

[John Ford [:jhford] CET/CEST Berlin Time]

(In reply to Jonas Finnemann Jensen (:jonasfj) from comment #9)
> @jhford,
> That seems nice...

Heh, yep!

> @jhford, can we rename taskcluster-logging to taskcluster-lib-log or
> something like that.

Yah, I can rename it.

> @jhford, ^ I think that is my last concern, do I give base.API an instance
> of log from my app or?

I think that we should have a small lib/log.js per library... if we do that, we could filter logging to ignore certain things.  Passing around log objects feels like a really bad idea to me.  I'd like to avoid it wherever it makes sense to.  There are going to be some child loggers that get passed around I suspect, like in the case:

for x in y:
  l = log.child({x: x})
  for i in j:
    ll = l.child({i: i})
    print x, i

If we were to split the loops into their own functions, we'd have to pass a log object around, but it'd likely be only for smaller internal only functions where the API isn't totally screwed up by having to pass in a log object.

Comment 12

[John Ford [:jhford] CET/CEST Berlin Time]

https://github.com/taskcluster/taskcluster-lib-log

Comment 13

[Pete Moore [:pmoore][:pete]]

lgtm :)

Comment 14

[John Ford [:jhford] CET/CEST Berlin Time]

Attachment: first review

Here's the Pull Request.  I'll upload a sample of how I converted the provisioner to this library using the compatibility stuff.

Comment 15

[John Ford [:jhford] CET/CEST Berlin Time]

Attachment: sample to use debug compatibility for aws provisioner v2

Comment 16

[Jonas Finnemann Jensen (:jonasfj)]

Comment on attachment 8677443 [details] [review]
first review

Okay, the code looks sane.
I'm just confused about how to use the library.
So the r- is related to a need for better docs.
Preferably shorter, more concise, and clear focus on how this is different
from raw bunyan, and what is and is not global.

Do I or do I not pass around a log object and create childs of it?
What is name and what is module, what is required?

Should I use this in libraries (do I pass a log object around?).
Note: I'm fine with either solutions, even not using it in libraries as most
libraires should throw errors rather an logging stuff
(maybe we have a few exceptions, like base.API).

Comment 17

[Pete Moore [:pmoore][:pete]]

Comment on attachment 8677443 [details] [review]
first review

Feeling a bit out of my depth here - I think I'll leave it to Greg and Jonas, as I'm not really actively developing in node. Thanks for checking with me though.

Comment 18

[Greg Arndt [:garndt]]

Comment on attachment 8677443 [details] [review]
first review

Looks like I forgot to remove this flag, but I think my initial comments are similar to Jonas'.  Also my immediate need for this library has taken a back seat as we are replacing docker-worker with a Go replacement.