cli: richer logs output

[tiborsimko]

Motivation

It would be nice to enrich the output of reana-client logs so that the logs would include important information of interest to the user, such as command to run and the execution environment, so that the user won't have to do it separately. Basically the logs command could gather this information from the workflow runtime execution context and then aggregate it for the end user into a rich log output.

Current behaviour

Currently, the logs for the RooFit example show:

$ reana-client logs
JOB LOGS
job id: 3aad152f-c087-4fc3-ab0e-1c2ee5fb74ed
job:


job id: 09c02de8-85d6-48fb-b96e-bfffe8572304
job:
    ------------------------------------------------------------
      | Welcome to ROOT 6.18/04                  https://root.cern |
      |   |
... many lines
... many lines
datasets
--------
RooDataSet::modelData(x)



job id: 4923b0fa-217b-4f28-9f54-5a19a081d70c
job:
    ------------------------------------------------------------
      | Welcome to ROOT 6.18/04                  https://root.cern |
... many lines
... many lines
[#1] INFO:Plotting -- RooAbsPdf::plotOn(model) indirectly selected PDF components: ()
Info in <TCanvas::Print>: png file results/plot.png has been created

This prints internal job ID (that is useful for debugging, but mostly for developers only) and the output of commands (that is useful for users, but it does not show which command run and where).

Expected behaviour

Since the workflow definition in richer, it would be good to see which command run, in which compute environment, right with the logs, something like:

$ reana-client logs
WORKFLOW: fd775f45-5f97-4401-a868-424d4ebdb1e3
JOB: 3aad152f-c087-4fc3-ab0e-1c2ee5fb74ed
STEP: gendata
ENVIRONMENT: reanahub/reana-env-root6:6.18.04
COMMAND: mkdir -p results
STARTED: 2020-01-23T11:00:00
FINISHED: 2020-01-23T11:01:00
STATUS: finished
STDOUT: None
STDERR: None

WORKFLOW: fd775f45-5f97-4401-a868-424d4ebdb1e3
JOB: 09c02de8-85d6-48fb-b96e-bfffe8572304
STEP: gendata
ENVIRONMENT: reanahub/reana-env-root6:6.18.04
COMMAND: root -b -q 'code/gendata.C(...
STARTED: 2020-01-23T11:04:00
FINISHED: 2020-01-23T11:12:00
STATUS: finished
STDOUT:
... many lines
STDERR
... many lines

WORKFLOW: fd775f45-5f97-4401-a868-424d4ebdb1e3
JOB: 4923b0fa-217b-4f28-9f54-5a19a081d70c
STEP: fitdata
ENVIRONMENT: reanahub/reana-env-root6:6.18.04
COMMAND: root -b -q 'code/fitdata.C(...
STARTED: 2020-01-23T11:13:00
FINISHED: 2020-01-23T11:14:00
STATUS: finished
STDOUT:
... many lines
STDERR:
... many lines

Basically, the REST API returning workflow run logs would enrich the current job-oriented reply with whatever can be gathered from the workflow engine execution runtime context.

(just an idea for illustration; the output format is subject to change)

Complexity

Beware of the JSON output mode. It would be good if this is nicely processable too by various clients. (including UI later)

Serial is different than CWL is different than Yadage, but some commonalities exist. We can define a nice common denominator and start with Serial.

See also engine-specific progress logs and friends. This issue is not about nice live streaming of progress, but about richer exposure of logs of what wealready have logged on the system. But it does not hurt to keep an eye on a future live log streaming, e.g. in a --follow kind of way.

Future outlook

This could lead to a future rich search syntax to extract only parts of log, such as:

$ reana-client logs -w roofit --step gendata --output stderr

Also, if we have inputs/outputs for Serial one day, the output could show full path to output files generated by each step:

INPUT: /var/reana/users/00000000-0000-0000-0000-000000000000/workflows/b5c435ae-aa6b-4f86-b22d-4cb42a0b876a/code/gendata.C
OUTPUT: /var/reana/users/00000000-0000-0000-0000-000000000000/workflows/b5c435ae-aa6b-4f86-b22d-4cb42a0b876a/results/data.root

Listing these future outlook thoughs here for the sake of a broad overview of where this might be going; the follow-ups will be separate issues once we have the basic functionality nailed down.

[lukasheinrich]

generally I think it would be useful if those commands had a --format json option so that the output could be machine-processed e.g. with jq

[tiborsimko]

We already have a --json option 😉 but the output is not so rich... Basically like the text one.
So this issue is about nicely enhancing the output with more information and prettifying it.

Here's the current JSON output (with cut values):

$ reana-client logs -w roofit --json | jq -S | less
{
  "engine_specific": null,
  "job_logs": {
    "09c02de8-85d6-48fb-b96e-bfffe8572304": "job: \n    ...",
    "3aad152f-c087-4fc3-ab0e-1c2ee5fb74ed": "job: \n  \n",
   "4923b0fa-217b-4f28-9f54-5a19a081d70c": "job: \n   ...",
 },
  "workflow_logs": ""
}

[lukasheinrich]

awesome!

…

On Mon, Jan 13, 2020 at 6:04 PM Tibor Šimko ***@***.***> wrote: We already have a --json option 😉 but the output is not so rich... Basically like the text one. So this issue is about nicely enhancing the output with more information and prettifying it. Here's the current JSON output (with cut values): $ reana-client logs -w roofit --json | jq -S | less { "engine_specific": null, "job_logs": { "09c02de8-85d6-48fb-b96e-bfffe8572304": "job: \n ...", "3aad152f-c087-4fc3-ab0e-1c2ee5fb74ed": "job: \n \n", "4923b0fa-217b-4f28-9f54-5a19a081d70c": "job: \n ...", }, "workflow_logs": "" } — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#348?email_source=notifications&email_token=AARV6A3N2W6LQQNIAA36U2TQ5SNIXA5CNFSM4KGFKJ22YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEIZPYSI#issuecomment-573766729>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AARV6A3JOPMOSOT7IZW4TRDQ5SNIXANCNFSM4KGFKJ2Q> .

[diegodelemos]

Closing once reanahub/reana-workflow-controller#282 is merged :)