1150362 - docker-worker: Add timestamps to task log format (discussion/proposal)

Status: RESOLVED WORKSFORME

(Taskcluster :: Workers, defect)

Description

[Jonas Finnemann Jensen (:jonasfj)]

Currently task logs are just TTY streams. We allow and support ANSI escape
codes, including complicated things like delete, etc...

I see two possible paths we could choose going forward:

Option 1) We log in a binary format:
  We support ANSI escape codes.
  We use ttyrec or termcap to add timestamps to the log.
   - http://angband.pl/termrec.html
   - http://0xcc.net/ttyrec/index.html.en
  Showterm.io is an awesome demo, but obviously we don't want playback in
  this way. It would, however, be awesome if we could print the log with
  timestamps.

Option 2) We log in text format:
  We only support text, we make docker-worker strip ANSI escape codes, etc.
  And we add a timestamp in front of each line.

(1) certain is the most powerful. But it does have some significant
drawbacks. Including because we have to render it using something like
term.js. We can render everything to one giant HTML file, because loading
it in a browser will be slow.
It's harder to search, copy/paste out because everything interacts with a
widget that only renders part of the log.

On the other hand, converting the binary log to plain text and showing it in
<pre> tag with overflow scroll would be trivial and perform well, even in the
browser. And it is possible to render rather large log files to HTML with
markup, this is what travis does, but the browser doesn't like it when we
add too many tags.

Either way, we should decide what kind of log format we want so inspectors
and tools we build to grep the logs can work efficiently.

I think need to add timestamps to log entries. And I think the binary format
we have is pretty decent, but I'm not sure we're willing to make the
investment/work necessary to display and take full advantage of a binary format.

Also we might need to do more research and experiments to decide what is best.

Comment 1

[Jonas Finnemann Jensen (:jonasfj)]

ANSI escape sequences in logs might be considered more of a bug than a feature, see bug 1154888.

Maybe we should just drop it? And find some syslog format thing? or something...
Ideally I would like docker-worker to add timestamp for each line.

We could also have multiple log files in different formats...?

Comment 2

[Greg Arndt [:garndt]]

I'm +1 for plaintext logs

Also, it would be nice if we could just dump various tagged logs to logserve and it can create various logs that we can view.  Such as one for the task container and one for docker related info about the containers or other data we want to have attached to a task for debugging/inspection.

Similar to how different apps can log to syslog, but logserve would split it up into different logs based on origin or perhaps the log viewer did that for us. 

Not sure, just an idea.

Comment 4

[(not currently active) Ted Mielczarek]

The ANSI color codes in logs are sure neat if they work properly through the whole pipeline (seeing it in Travis logs is cool), but if that's going to be a hassle it might not be worthwhile.

Comment 5

[Jonas Finnemann Jensen (:jonasfj)]

we could easily translate ANI colors codes to HTML, I just fear it would slow to load in-browser when logs grows to multiple megabytes.

Anyways, maybe it's one of those cases where we can always add more fancier logs. But text is simple and very robust.

Comment 6

[Gregory Szorc [:gps]]

You should be using structured logs. Then, you can prettify things at view time (terminal codes, HTML, etc) rather than at event generation time. See how mach does it.