If you think a bug might affect users in the 57 release, please set the correct tracking and status flags for Release Management.

docker-worker: Log behind a pref (or piggy back on DEBUG)

NEW
Unassigned

Status

Taskcluster
Worker
3 years ago
a year ago

People

(Reporter: lightsofapollo, Unassigned)

Tracking

Details

(Whiteboard: [docker-worker])

(Reporter)

Description

3 years ago
The log output is massive when hacking on the docker-worker obscuring useful details .. We should hide the logs by default locally.

Aside: I think we should replace debug module with something that logs a more structured json format (but has the same pretty behavior enabled by default)
I think debug() makes sense for many things... It's certainly useful when you're debugging locally.
It's not a good way to provide a lot of data I totally agree! But the rest of our eco-system uses debug(), dropping it completely is a bad idea.

I think we should use something like this lib/log.js:

var DEBUG = require('debug'); // not specifying namespace here

var log = function(json) {
  assert(typeof(json.namespace) === 'string', "Structured log message must have a namespace");
  if (DEBUG.enabled(json.namespace)) {
    console.stdout.write(JSON.stringify(json) + '\n');
  }
};

This^ way we can limit logging using the DEBUG variable, but also have structured logs.
I still think it useful to have some text logging with debug(), but those logs should be short.

Note: I tried to do this but current tests actually reads from stdout, WTF? hehe... We should not do this:
https://github.com/taskcluster/docker-worker/blob/2005a30ad74cc2b9e9f7166016a5ace89a114624/test/testworker.js#L92-L94
If it's for IPC we should use process.send(...), if it's not for IPC just emit an event.
For process.send see: https://github.com/taskcluster/taskcluster-base/blob/4e4b44ec8bfe9ce14c40ef5a8cce89bbbb861694/app.js#L129-L138

In fact you can use taskcluster-base to do the signaling using app.js and base.testing has a localworker like thing...
(Reporter)

Comment 2

3 years ago
> Note: I tried to do this but current tests actually reads from stdout, WTF? hehe... We should not do this.
 
Qualify this ? Being able to read the state of the application from the logs for testing makes verifying state way easier without hacks. process.send works in a limited fashion but running the application in docker opens up way more options (like testing things on the networking stack like the live log tests do).

Lots of our components use "debug" I think I started this and it works really well in some other places I used it for CLI type interfaces (test) It is pretty terrible for ingestion on the server side. At least in the docker-worker we have tons of state flying around in various components and having something like loggly make sense of all the logs is more then worth it.
I don't understand the obsessions with wrapping the host-code in another layer of abstraction... It's just going to complicate things development and testing. Devs will already want to run host-code in vagrant.

I know you can deploy with docker then, but then we have to distinguish between updates we can roll out with a docker image and updates that require a new AMI (partitioning things, etc).
You risk introducing another a new dependency hell :)
(IMO process isolation should be good enough)

Anyways, if we want to rely on things from stdout... we should somehow make that clear. And not stuff the parts communicating in tests in with things that pollute the log UI to a point where you can't see which tests failed and which tests passed.
Component: TaskCluster → Docker-Worker
Product: Testing → Taskcluster
Whiteboard: [docker-worker]
Component: Docker-Worker → Worker
You need to log in before you can comment on or make changes to this bug.