[feature] Provide logging command outputs for Azure Devops CI

[KarstenB]

We are running Conan in our CI on Azure Devops and right now we are parsing the generated console output to identify Conan output, warnings and errors. This is done using a regex, which is very prone to mismatching as Conan does not give very strong identifiable console output.

Some of these messages we transform into logging commands which are easier to identify in a log and also get warnings and error to the the summary part of a build job.

I can see 3 different ways of making it easier to identify/parse issues:

1. Add an environment variable that prepends a token (i.e. CONAN:) to every output. This is how we deal with ninja progress output. This is really simple to implement and would work sufficiently well for my use-case
2. Enable hooks to replace self.output by providing a factory for the output. Simply setting conanfile.output in each hook method currently does not work because some commands rewrite their output with scoped outputs.
3. Integrate output in the logging command format for azure (I am sure we are no the only ones using Conan in a CI).

Did I miss another way of achieving my goal?

• [x] I've read the CONTRIBUTING guide.

[memsharded]

Hi @KarstenB

As Conan 1.X is now in "migration mode", and the efforts are fully focused on 2.0, I think it is worth to reformulate this issue for 2.0. A few changes have been done:

• All messages that are not the "final result" are sent to stderr
• Added explicit verbosity in the loggers, together with a --logger that changes the output to json:

  def add_log_level_args(subparser):
  subparser.add_argument("-v", default="status", nargs='?',
                         help="Level of detail of the output. Valid options from less verbose "
                              "to more verbose: -vquiet, -verror, -vwarning, -vnotice, -vstatus, "
                              "-v or -vverbose, -vv or -vdebug, -vvv or -vtrace")
  subparser.add_argument("--logger", action="store_true",
                         help="Show the output with log format, with time, type and message.")

  It could make sense to add some new argument to pre-pend some string.

However, I'd like to understand better the issue. If the problem is separating the Conan output from other commands that the CI execute, isn't this easy? The output of the Conan commands can already be fully captured/redirected, and separated from other commands? If it is to collect just the warnings and errors, those indeed have identifiable patterns, aren't they?

[KarstenB]

The patterns I currently use are:

    conan_warning = re.compile(r"(?:.*?: )?WARN: (.*)")
    conan_error = re.compile(r"(?:.*?: )?ERROR: (.*)")
    conan_info = re.compile(r"(?:.*?: )?(.*?\/.*?(?:@.*?\/.*?)?): (.*)")

The warn and error are borderline ok, but plenty of other tools use error: in their output. What I did not handle is the case where you have a scope in a scope situation. The problem is that Conan is logging in a stream of other output. When you call conan create you might get output from MSBuild, CMake, Ninja, Gcc, Clang etc. (where we use other regex' to filter out the warnings and errors). The conan_info however also matches with linker warnings /usr/bin/ld: bla: xyz. Prepending a string would make those Regex' plenty strong and unique.

To be fair I have not tested Conan 2.0 just yet, but the logger argument sound like it may be useful for this purpose, but unfortunately knowing my organisation, it will probably take a long while before upgrading. I also would like to have the output in real-time (so that the user can see what is happening, and did not just hang) and not just a final errors.json.

So I will take a look at Conan 2.0 and give you feedback about the new output options.

[KarstenB]

Hey @memsharded, I finally got around to check our recipes with Conan 2.0 and found that the --logger output would indeed fill my requirements of being able to properly parse and detect messages, and I would love to direct it to a file. However I think that it is a bit over the top when written to a common log file that can then be easily read by a dev posts-mortem.

So over all I would still prefer to have a prefix to all output.

[memsharded]

We agree that the --logger is too much, and it is going to be removed as a bug in 2.0.1

We will need to figure out about the prefix, lets aim for 2.1

[memsharded]

Hi @KarstenB

As we move to 2.1, I am re-checking this. I have some concerns:

• I don't see other tools (cmake, compilers, other build systems) that have any configuration to prefix their outputs. You commented that you are customizing ninja but I haven't been able to find any reference
• I am not concerned about adding an env-var that always prefixes. But I am concerned about the derivatives of this features, users wanting to prefix with timestamps and other stuff, requiring to invent and maintain a custom syntax for this. This is often too painful for us, the maintenance, support, docs, etc that it causes, we are already overwhelmed, all these things compound, so we really need to choose carefully everything we add.

[KarstenB]

For Ninja I am using the NINJA_STATUS environment variable. I think a key difference for compilers for example is that it is a tool that you call, that will not call other tools (technically not true, but it feels very integrated into one product).

CMake has the "advantage" of having messages look quite unique so that they are easy and reliably to identify with a regex.

Conan uses an output pattern that looks quite similar to for example a linker error. I totally agree on your concerns of opening a Pandora box, and to be frank I would still prefer the programmatic way of somehow replacing self.output reliably in my recipes, but it takes a lot more effort to implement.

[memsharded]

I have tried to push this to the team, but it seems there is no consensus so far. The NINJA_STATUS seems more focused on information about rules than a logging differentiator mechanism, and other tools do not have anything similar, so Ninja seems the exception here.

I am not closing this yet as not planned, I'll try again, but at the moment not in 2.1 scope