1055070 - mozlog should have a way to configure ad-hoc formatting

Status: RESOLVED WONTFIX

(Testing :: Mozbase, defect)

Description

[Chris Manchester (limited bugmail, email directly)]

One off formatters for harness specific formatting that isn't taken care of by the tbplformatter have proved to be the rule, not the exception. We have one for marionette and mochitests, and I'm pretty sure I'll end up needing one before the xpcshell conversion is complete.

It doesn't seem like putting these in the standard set of configurable formatters in commandline.py makes much sense, because they're unlikely to be useful outside of a particular harness, but this has the drawback that the other setup/configuration capacities provided in commandline.py are not available to these users.

So I'd like to have an explicit place to apply some ad-hoc formatting that commandline.py knows about. We can think of them as "modifiers" for existing formatters. This will also help us transition away from legacy formatting as we propagate structured logging: we can start with some output modifier specified in the 'defaults' argument to setup_logging, then just pass in a commandline flag for automation runs, and eventually do away with it completely.

Comment 1

[Chris Manchester (limited bugmail, email directly)]

Attachment: mozlog should have a explicit, configurable way to apply additional formatting.

This is what I have in mind. This can't land as one chunk because marionette will need a mozlog release, but you get the idea.

Comment 2

[Chris Manchester (limited bugmail, email directly)]

https://bugzilla.mozilla.org/show_bug.cgi?id=1044136#c9 and bug 1051023 motivate this as well.

Comment 3

[Andrew Halberstadt [:ahal]]

Comment on attachment 8474613 [details] [diff] [review]
mozlog should have a explicit, configurable way to apply additional formatting.

I'm not really too crazy about this 'mod' concept. I think it's starting to make things overly complicated. Can't we just let the test harnesses register their custom formatters so it shows up in the commandline help? Preferably overriding the default formatter it is subclassing? I'm also not really crazy about harness specific logic living in mozlog.

That being said, if you and James both want to go this route, I won't get in the way :).

Comment 4

[Andrew Halberstadt [:ahal]]

For an idea of what the registering thing might look like.. maybe the setup_logging function could have a 'custom_formatters' argument that takes a list of classes. It would then check if any of the formatters subclass any of the default formatters. If so, it could replace the default. If not, it could add a new entry to 'log_formatters'.

Comment 5

[James Graham [:jgraham]]

Comment on attachment 8474613 [details] [diff] [review]
mozlog should have a explicit, configurable way to apply additional formatting.

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

Sorry, I forgot to transfer our irc discussion here.

Basically I agree with ahal. I think we should either try to hoist the requirements up to the top level formatter where it makes sense (the traceback case might be one of these), or allow the testharness to customise the formatter classes (this is basically already possible, I think).

I don't think we should introduce this concept of modifiers because I think it a) gives tight coupling between test harnesses and mozlog baked into mozlog (to the extent this is needed it's better to bake this into the individual consumers) and b) offers a rather useless axis of configuration (if the modifiers are doing harness-specific things then there should be no reason to apply the modifier from one harness to the output from another).

Comment 6

[Andrew Halberstadt [:ahal]]

(In reply to Andrew Halberstadt [:ahal] from comment #4)
> For an idea of what the registering thing might look like.. maybe the
> setup_logging function could have a 'custom_formatters' argument that takes
> a list of classes. It would then check if any of the formatters subclass any
> of the default formatters. If so, it could replace the default. If not, it
> could add a new entry to 'log_formatters'.

Er, I guess it would be "add_logging_group" that would need the 'custom_formatters' argument. Or potentially even a brand new 'register_formatters' function could do it.

Comment 7

[Andrew Halberstadt [:ahal]]

Eh, and also ignore me about the auto-detecting subclass thing :p.. registration shouldn't need to be more difficult than "log_formatters.update(custom_formatters)", then harnesses can decide whether it overrides or not.

Comment 8

[Chris Manchester (limited bugmail, email directly)]

Yeesh, tough crowd. Subclassing is probably the most palatable way to deal with this although some of the things I've stuffed in here will apply to multiple harnesses, so we'll need more formatters in a shared location as well as hanging around our harnesses (for instance, logging a smaller set of statuses to make output closer to legacy is something requested for marionette, mochitest, and will make sense for xpcshell, although because it actually makes output less informative in some cases I don't think it should be in the base tbpl formatter for other users).

Maybe I've presented this wrong: instead of "marionette output modifier" we could think of it as "exception message first stack trace modifier", and instead of "mochitest modifier" it's "line number level prefix" modifier. They always have to be applied in an order that makes sense, but I don't think it's all that complicated. I think it's less complicated than having formatters all over the tree.

Ad hoc formatters getting access to the commandline configuration is the main thing I'm trying to solve (bug 105537 was raised this morning coincidentally). I think Andrew's idea will work -- James do you want to weigh in on this before I implement? Or maybe you have something else in mind when you mention customizing formatter classes?

Comment 9

[Chris Manchester (limited bugmail, email directly)]

Of course I mean bug 1055537

Comment 10

[James Graham [:jgraham]]

Updating the formatters like ahal said is quite reasonable. If there are things that are common to several harnesses but not all e.g. only outputting a few statuses, we could put those in mozlog as e.g. ReducedStatusTbplFormatter, not add it to the default list of formatters, but have those harnesses do log_formatters.update({"tbplformatter":structuredlog.formatters.tbpl.ReducedStatusTbplFormatter}) or something.

That said, I really think we should examine use cases hard and try to solve our problems with as few special cases as possible. For example I still don't understand why the marionette case can't be adapted to use a generic solution.

Comment 11

[Chris Manchester (limited bugmail, email directly)]

Sounds like a plan.

The issue with marionette is that the way we're hooking into the unittest library in the moztest adapter provides a message that isn't compatible with starring. Our generic solution is defying our requirement, so I resorted to a special case in the formatter.

Comment 12

[Chris Manchester (limited bugmail, email directly)]

Bug 1055679 to deal with the underlying issue in marionette. I think log_formatters.update() with a subclass will address this for other cases.