In verbose mode, errors are sent to stdout

[LasseBlaauwbroek]

When executing an install command in --verbose mode, any messages that are printed to /dev/stderr by a build command are redirected to /dev/stdout by Opam. It would be better if they would still end up in /dev/stderror, because this allows for easy separation of errors and normal messages.

[rjbou]

You can use for that the environment variable OPAMMERGEOUT

[LasseBlaauwbroek]

Ah, I didn't know about that one. Thanks. However, I just tried to run

export OPAMMERGEOUT=0 && opam install . --verbose 1> /dev/null

on my project, and it does not display any errors, even though I know that running the exact same build command that Opam uses does produce warnings on stderr. So either I'm using it wrong, or there is a bug somewhere.

[rjbou]

It unmerges outputs for command outputs files. By default, stderr & stdout are merged in .out file. Those files are in .opam/log (unless you select another one with OPAMLOGS). They are displayed in the error report when an error occurs. In a successful run, file names are not logged at all (we should at least add it at a 2+ debugging level). For the moment you can clean your log dir (or create a temp new one) and look at those files: pkg-xxx-.info file gives the command ran, and pkg-xxx.{err,out} corresponding outputs (if unmerged).

On direct opam output, stderr is used for debug logs and error reports.

[LasseBlaauwbroek]

Note that even during a successful run, warnings can still be printed to stderr by the build command. Given that OPAMMERGEOUT can separate pkg-xxx.err and pkg-xxx.out, it would make sense to me that --verbose mode would also send these logs to the proper terminal outputs. Or am I still misunderstanding?

[rjbou]

It makes sense yes, but it's not so trivial (display x.err in stderr) to implement as it need to give the context. As some actions are done in parallel, user can't know from which action originates the warning. One solution could be, when outputs are unmerged, to display a warning report, like the errors one.

@AltGr what's the original reason for the merged outputs?

[AltGr]

From experience, although it's counter-intuitive, you generally lose more information by separating stderr and stdout ; the reason being that relative ordering generally matters, and is in many cases a more relevant information than wether each line was printed to stdout or stderr. For example, a compiler may print the context to stdout, then an error to stderr.

I believe --verbose will only work for stdout, if you disable output merging, which might be your issue. I don't know what your use-case is, but you might be interested in the --json output which includes the build logs.

[LasseBlaauwbroek]

From experience, although it's counter-intuitive, you generally lose more information by separating stderr and stdout

Yes, this is indeed true. However, in this case, a large amount of information was printed on stdout, and I wanted to know if there were warnings printed to stderr at all. Then it is useful just to check if something gets printed to stderr at all. However, I guess I can also look at pkg-xxx.err instead. So this is not a super critical problem, just unexpected.

I don't know what your use-case is, but you might be interested in the --json output which includes the build logs.

That is indeed an interesting option. However, on opam 2.0.7, when I run opam install xxx -v --json=test.json, the resulting json does not contain a build log, nor a link to a file containing a log:

{"opam-version":"2.0.7","command-line":["opam","reinstall",".","--json=test.json","--verbose"],"command-line":["opam","reinstall",".","--json=test.json","--verbose"],"switch":"/home/lasse/Documents/Projects/Tactician/develop","request":{"action":"reinstall","install":["coq-tactician.8.11.dev"],"remove":[],"upgrade":[],"criteria":"-changed,-count[version-lag:,false]"},"solution":[{"remove":{"name":"coq-tactician","version":"8.11.dev"}},{"install":{"name":"coq-tactician","version":"8.11.dev"}}],"results":[{"action":{"build":{"name":"coq-tactician","version":"8.11.dev"}},"result":"OK","duration":4.4425950050354},{"action":{"remove":{"name":"coq-tactician","version":"8.11.dev"}},"result":"OK","duration":0.0446019172668457},{"action":{"install":{"name":"coq-tactician","version":"8.11.dev"}},"result":"OK","duration":5.933771848678589}]}

[LasseBlaauwbroek]

Mhm, but now that I'm trying this again, it seems that there are also problems with he logs:

1. Opam only keeps logs in .opam/log/ when a build fails, even if set set OPAMKEEPLOGS.
2. Opam does not respect OPAMLOGS. Log files always end op in .opam/logs/, even if I set something like export OPAMLOGS=$(pwd).

[dra27]

This was discussed this morning. Steps:

• [ ] https://github.com/ocaml/opam/issues/4490#issuecomment-762339185 needs to be triaged/reproduced/fixed
• [ ] We need to verify that OPAMMERGEOUT=0 is behaving correctly w.r.t. the logs written in ~/.opam
• [ ] Propose for opam 2.2 that OPAMMERGEOUT=0 opam --verbose should write always write the stderr logs to stderr (once that's been double-checked that it's not already the case!)