Colorize colcon output

[yossioo]

Greetings.

I propose a colorized version of colcon's output.
Tested on Ubuntu 18.04, with ROS2 Dashing.

Screenshot is here.

[yossioo]

Well, After seeing failed checks I realized that the solution is only good for Linux, and I didn't test it on Windows at all.
Also, it seems that Travis CI also failing, mainly because of me not aligning the code properly (?correct me if I'm wrong).

I failed to find some instructions on testing these things before actually submitting a pull request, and I will be glad if someone will point out what can I do to complete the solution and actually have this feature implemented in colcon :)

[dirk-thomas]

Thank you for working on this enhancement.

After seeing failed checks I realized that the solution is only good for Linux, and I didn't test it on Windows at all.

Yeah, any patch should work across all supported platforms (as long as that is feasible).

it seems that Travis CI also failing, mainly because of me not aligning the code properly.

That sounds right. The code style follows PEP 8 and uses flake8 (with some plugins) for checking.

I failed to find some instructions on testing these things before actually submitting a pull request

Beside building your changes in the colcon-core package locally you can also simply call colcon test --packages-select colcon-core to run all the tests of the package which include the linters.

[mikepurvis]

The way catkin_tools handles this is that the actual logic outputs bare strings, and then there's a translation process (similar to translating for another human language) which swaps those out for colorized versions based verb-supplied lookup maps:

https://github.com/catkin/catkin_tools/search?q=_color_translation_map

[dirk-thomas]

@yossioo Are you interested to iterate on your PR?

[yossioo]

@yossioo Are you interested to iterate on your PR?

Definitely! I am eager to see colorful colcon output released :D

Do you think I should stick with this approach but add some system checks to constrain solution to be Ubuntu only?
Or should I try to implement the color map like @mikepurvis mentioned?

Update:
I see that you added integration of coloredlogs package, can it be applied for the standard colcon output?

[dirk-thomas]

Let me try to summarize my perspective:

• colcon has a very modular design. A perfect solution would keep the aspect of colorizing the output separate from all the other logic.
• A solution should be as little invasive as possible. Atm existing code simply invoked print().
• The colorization needs an automatic default (e.g. if isatty) but also allow manual override (force-disable, force-enable).
• "Intercepting" printed lines and then trying to apply colorization to them sounds problematic since the same content might need different handling depending on its content. E.g. a message printed by a specific event handler should be colorized while the same output coming from a command invocation should not be.

With this wish list I currently don't see how this could be implemented. And if not all goals can be satisfied I am hesitant to decide which one should be / needs to be dropped.

Any suggestions are very welcome.

[mikepurvis]

The interception-based approach (like how catkin_tools works) should be workable with a small amount of additional metadata. Could be as simple as a mode stack that you can push items onto before emitting a particular type output and then pop them off again afterward.

Or just use the logging framework's LoggerAdapter to have different logger objects for different contexts: https://docs.python.org/3/library/logging.html#loggeradapter-objects

Even with zero additional effort to inject color into existing outputs, this would still allow adding some small niceties like coloring a command's stderr differently from something that was logged directly by a colcon module or plugin.

[dirk-thomas]

The interception-based approach (like how catkin_tools works) should be workable with a small amount of additional metadata. Could be as simple as a mode stack that you can push items onto before emitting a particular type output and then pop them off again afterward.

Can you sketch a snippet how you imagine the invocation to look like?

Or just use the logging framework's LoggerAdapter to have different logger objects for different contexts: https://docs.python.org/3/library/logging.html#loggeradapter-objects

Currently the messages which should be colorized are not using the logging API.

Even with zero additional effort to inject color into existing outputs, this would still allow adding some small niceties like coloring a command's stderr differently from something that was logged directly by a colcon module or plugin.

How would you distinguish these two cases - a commands output printed in one place and a random status message printed somewhere else?

[mikepurvis]

I'm surprised you're not using logging, as I would have thought it would be a good fit for this kind of project. Is there some objection, or just didn't see the need?

I don't have much familiarity with the colcon codebase, but from a brief look, it seems that the start/end messages are emitted with {{print()}} here, one of which uses {{file=}} to direct them to stdout or stderr as appropriate:

https://github.com/colcon/colcon-core/blob/master/colcon_core/event_handler/console_start_end.py

This would be easy to handle with logging, by instantiating a named logger on import, eg:

import logging
logger = logging.getLogger('colcon.console_start_end`)

And then later on, send messages to it with logger.info and logger.warn. This would avoid having to hardcode details like sys.stdout into the logic, and perhaps make it easier down the road to do things like turn on precise timestamps for all messages when debugging, where all that stuff could be suppressed by a basic Formatter in the default case.

Handler instances determine which Formatter is used for a particular message. So the colorizing Formatter could be one of several options, with rules that direct particular logger names to coloring or non-coloring formatter. The command output would just have to be sent using a differently-named logger, something like colcon.command_output.

Anyhow, if this is of interest I could look at preparing a more extensive example (eg, porting enough of colcon to it to more fully demonstrate the principle), but that would likely be several weeks away.

[dirk-thomas]

I'm surprised you're not using logging, as I would have thought it would be a good fit for this kind of project. Is there some objection, or just didn't see the need?

colcon does use logging for actual debug/info/warn/error message logging. Those are printed with the common format string (see

colcon-core/colcon_core/logging.py

Line 16 in e45426e

'COLOREDLOGS_LOG_FORMAT', '%(name)s %(levelname)s %(message)s')

) and are also colorized.

The "normal" output is using just plain print() since I didn't see a reason why they should use logging. Certainly that could be revisited if we see a need for it now. I am just not entirely sure how using logging would help us achieve the goal of this ticket while also assuming we don't want the log format format to be applied, nor the log level colorization (a custom formatter as you suggested should work for that) or the log level threshold filtering?

How do you imagine the custom colorization to come in then? Would some Python code register a custom formatter for a known name and then insert ASCII sequences for known message strings (similar to the mapping in catkin_tools)?

perhaps make it easier down the road to do things like turn on precise timestamps for all messages when debugging

The log files already have timestamps on each line.

[codecov-io]

Codecov Report

Merging #195 into master will increase coverage by 1.79%.
The diff coverage is 60%.

@@            Coverage Diff             @@
##           master     #195      +/-   ##
==========================================
+ Coverage   78.09%   79.89%   +1.79%     
==========================================
  Files          53       55       +2     
  Lines        3059     3173     +114     
  Branches      512      525      +13     
==========================================
+ Hits         2389     2535     +146     
+ Misses        642      595      -47     
- Partials       28       43      +15

Impacted Files	Coverage Δ
colcon_core/event/__init__.py	100% <ø> (ø)	⬆️
colcon_core/event/output.py	100% <ø> (ø)	⬆️
colcon_core/verb/test.py	28.15% <ø> (ø)	⬆️
colcon_core/argument_parser/__init__.py	100% <ø> (ø)	⬆️
colcon_core/event/job.py	100% <ø> (ø)	⬆️
colcon_core/task/__init__.py	98.98% <ø> (+7.07%)	⬆️
...lcon_core/argument_parser/destination_collector.py	100% <ø> (ø)	⬆️
colcon_core/event/command.py	100% <ø> (ø)	⬆️
colcon_core/verb/build.py	0% <ø> (ø)	⬆️
colcon_core/event/test.py	75% <ø> (ø)	⬆️
... and 28 more

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 7f26625...8effab0. Read the comment docs.

[xqms]

Hey, I just looked at Dirk's analysis of the problem above and thought I could propose a solution: We could intercept all output and search for color format strings (something like #[red]Hello#[normal]). On platforms and terminals that support color, these are translated into escape codes, otherwise they just disappear.

So far so good (I guess this was also @dirk-thomas and @mikepurvis idea). The problem is where to put this interceptor, and I think we need to put it in colcon-core. Other plugins need to be able to assume this feature is present, since detecting its presence and only then using color codes is quite annoying and will introduce a lot of noise into the code.

To answer Dirk's question, I would weaken his first point. Colcon is highly modular, yes, but at least a default #[.*] string detection and deletion mechanism needs to be in the core, so that other plugins can write these annotations without fearing that they get printed. If required, the colorization itself could be in a plugin that registers as a "print handler" or something similar.

We could also have more semantic annotations like #[warning]Hello#[normal] or another format like #warning[Hello]#...

Thoughts?

[dirk-thomas]

We could intercept all output and search for color format strings (something like #[red]Hello#[normal]). On platforms and terminals that support color, these are translated into escape codes, otherwise they just disappear.

If every code line which prints a message already includes for colorization information in the message, what is the benefit of using a custom format and not simply ASCII control characters?

The main question is: do we really want all code to be aware of this aspect and include colorization information in each message or do we want the colorization to come in orthogonality as it is done in catkin_tools?

To answer Dirk's question, I would weaken his first point. Colcon is highly modular, yes, but at least a default #[.*] string detection and deletion mechanism needs to be in the core, so that other plugins can write these annotations without fearing that they get printed. If required, the colorization itself could be in a plugin that registers as a "print handler" or something similar.

The fact that colcon doesn't require all code to use a custom output-message function but just print() is something I rather don't want to give up. Maybe a filter can be registered which provides the conditional filtering of ASCII codes (assuming we can ensure that it only filters those desired and provides a way to explicitly set the mode using either with a command line argument or environmemt variable).

[xqms]

If every code line which prints a message already includes for colorization information in the message, what is the benefit of using a custom format and not simply ASCII control characters?

• I don't know if they are portable. I think some basic ones (ANSI) are supported on nearly all systems, but anything above that is system-dependent. Actually, Windows does not support them by default (https://en.wikipedia.org/wiki/ANSI_escape_code#DOS,_OS/2,_and_Windows)
• Writing them directly is no fun and will lead to pretty unreadable strings. I know that even a human-readable format like the one I proposed above is not much better, but still.
• If you want to pipe output to a log file (or anything that is not a tty), you probably want to print the raw text without escape codes. Stripping ANSI codes is actually not that easy.

But I see your point, it's probably a simple viable solution to constrain support to ANSI codes (e.g. 8 colors) and to somehow hook a filter for them into print() in colcon_core. The filter would have to strip the codes if there is no TTY or if color is otherwise disabled, and translate escapes to console calls for the Windows platform.

[dirk-thomas]

I don't know if they are portable.

E.g. [colorama[(https://pypi.org/project/colorama/) provides a way to make this work cross platform.

Writing them directly is no fun and will lead to pretty unreadable strings.

Commonly human readable variables containing these ASCII codes are being used.

Stripping ANSI codes is actually not that easy.

Can you elaborate why you think that is the case?

[richard-hajek]

Stripping ANSI codes

Not OP, but I assume the fact that ANSI codes may have different lengths depending on content so AFAIK you have to understand the ANSI codes to be able to remove them.

EDIT: But I presume there should be many libraries for that

[Flova]

I think this is superseded by #487