Ampoule logging is exceedingly verbose

[moshez]

Ampoule copies each child's output into the parent's log output. Since the child is also using Twisted logging, this results in log messages with lots of duplicate information. For example,

2010-04-03 15:11:04-0400 [-] FROM 0: 2010-04-03 15:11:04-0400 [HTMLOnlyPageGetter,client] Found links [...]

This would be better if the redundancy were elided. For example, formatting the above event like this instead would a bit of an improvement:

2010-04-03 15:11:04-0400 [Ampoule 0,HTMLOnlyPageGetter,client] Found links [...]

This preserves all of the information, but presents it better.

One approach which could work to implement this would be to have the child processes use a different logger. Rather than writing to stdout, it could make AMP calls back onto the parent with the log information.

Meanwhile, the parent would implement a receiver for these logging commands which re-published them to the log observer in the parent. The system keyword argument to log.msg can be used to make sure the information about which child the event is from is preserved.

[ldanielburr]

Now that #29 has merged, we could consider if some of the flexibility of twisted.logger's improved event formatting support solves this problem.

[ldanielburr]

Brief update: so this is actually kind of hard, because in the example shown here, the log output in question is being generated by a combination of twisted.python.log and twisted.logger, which makes controlling the formatting harder.

Example: run the ampoule test suite with trial, and note all the occurrences of "[-]", even though the new logger code is in use within ampoule. The reason we see "[-]" instead of "[whatever.the.logger.namespace.is]" is because trial is still using t.p.log, which ignores the log_namespace event key altogether.

[glyph]

@ldanielburr If anyone were to have time for this, the right way to attack it would be "eliminate uses of twisted.python.log"