Handle ASTE and preCICE logging #136

fsimonis · 2022-08-23T09:38:20Z

This PR changes the ASTE logger to:

Tags log entries from ASTE using the constant boolean attribute ASTE.
~~Output only ASTE log entries by filtering ... and %ASTE% in the sink.~~
Adds additional attributes for Participant and Rank. This allows to distinguish log entries when running ASTE in parallel.

After this, preCICE will still output ASTE logs by default. A similar change will soon be merged in preCICE itself.
Until then, we can configure a log filter in preCICE ... and not %ASTE% to remove ASTE log entries from the preCICE log.

edit: ASTE will now handle logs from both preCICE and ASTE.

preCICE configs should disable all sinks by defining <log enabled="false"></log>

Related to #73

davidscn · 2022-08-23T11:27:54Z

The preciceMap file was renamed. You can easily resolve the conflict here by renaming your preciceMap file locally and rebasing on the current develop. Please let me know if you want me to do that.

fsimonis · 2022-08-23T11:58:35Z

@davidscn I happily accept your offer 😉

davidscn

Tested the changes now with the corresponding precice branch. First of all, the PRs resolve the logger ambiguity, thanks!
However, we have in ASTE in addition to ASTE_INFO and ASTE_DEBUG ASTE_WARN and ASTE_ERROR, which were colorized and prepended by a corresponding keyword (e.g. ERROR). The colorization and the keyword are gone. See below for some other comments.

src/precice-aste-run.cpp

src/logger.cpp

davidscn · 2022-08-24T06:28:22Z

src/logger.cpp

+
+void addLogSink(bool verbose)
+{
+  std::string filter = "( %Severity% >= ";


Do we want to filter according to the primary rank by default?

Especially in ASTE, it can be useful to see how the various ranks are processing the mesh data. I found this very valuable while improving this part of the application.

fsimonis · 2022-08-24T07:28:55Z

I got more info from the boost team and will change the implementation slightly.

fsimonis · 2022-08-24T12:19:44Z

I had a new go at this as I just learned formatters can be conditional (boostorg/log#193).

ASTE now handles all the logging. preCICE logs (aka sinks) should be turned off.

davidscn · 2022-08-26T06:41:41Z

With this approach, the preCICE logger won't be configurable any more, right?

fsimonis · 2022-08-26T10:26:31Z

With this approach, the preCICE logger won't be configurable any more, right?

Yes and no.

ASTE enforces a format and filter for everything. You can still use --verbose to enable debug in both ASTE and preCICE (if available).

In addition, you can still use the preCICE config for additionally logging detailed information. Say debug of a specific module. You could then set the sink to a file and have only your required information in a format that is most useful for you.
Example: filter="( %Participant% == A ) & ( %Severity% == debug ) & ( %Module% endwith Mapping )"

davidscn · 2022-08-31T08:18:21Z

In addition, you can still use the preCICE config for additionally logging detailed information. Say debug of a specific module. You could then set the sink to a file and have only your required information in a format that is most useful for you.
Example: filter="( %Participant% == A ) & ( %Severity% == debug ) & ( %Module% endwith Mapping )"

I see, this will potentially lead to duplication in the logging, but probably be inevitably when handling the logging this way.

Could you please rebase? The mapping tester example using this logging configuration fails for me and the CI back then didn't fail (but will do now).

aste/tools/mapping-tester/config-template.xml

Lines 5 to 8 in 97cab85

    
           <log enabled="true"> 
        
             <sink type="stream" output="stdout" filter="%Severity% > debug" format='%TimeStamp(format="%H:%M:%S.%f")%|%Participant%|%Rank%|%Module%|l%Line%|%Function%|%Severity%%Message%' enabled="true" /> 
        
             <sink type="file" output="debug.log" filter="" format='%TimeStamp(format="%H:%M:%S.%f")%|%Participant%|%Rank%|%Module%|l%Line%|%Function%|%Severity%%Message%' enabled="true"/> 
        
           </log>

EDIT: I think the fail here is related to the preCICE logging branch. Which of the configurations here is invalid?

fsimonis · 2022-09-07T10:10:02Z

According to the documentation of boost log, the expression templates for filters and logs perform better than the parsed filters and formatters. So, ASTE using a fixed format should reduce logging overhead too.

davidscn · 2022-09-19T06:54:04Z

Remaining points to discuss:

The config logger settings are now mostly useless, unless someone wants additional loggings. We should remove the logger settings from all config files.
Do we want to go with this logger format?

---[preCICE:A:0] (impl::SolverInterfaceImpl in configure) I am participant "A"

Considering that the verbose flag refers to a debug log in preCICE, we could add the function only in a verbose mode. I don't see much advantage for having the function name printed by default.

fsimonis · 2022-09-19T08:35:37Z

Today, we talked about colorizing log levels as well as participant names differently.

We could add some more options to handle this as well as #136 (comment).

We need verbosity, colorization, and a filter for all vs primary only/no secondaries.

Suggestion: use non-verbose, colorized output from all ranks by default

Options to implement:

--verbose (which we already have) enables the output of debug information and enabled the %Module% in %Function% part of the log
--no-color disables the output of colors
--only-primary prints only logs from rank 0

Problem now is which colours to use for the Participants? Are they allowed to clash with the severity levels? Would a bold font be enough?

There are also no that many colors available if we stick to ASNI color codes.

       31        set red foreground
       32        set green foreground
       33        set brown foreground
       34        set blue foreground
       35        set magenta foreground
       36        set cyan foreground
       37        set white foreground

There are more options though https://chrisyeh96.github.io/2020/03/28/terminal-colors.html

davidscn · 2022-09-19T09:04:55Z

Suggestion: use non-verbose, colorized output from all ranks by default

To avoid complications, I would propose to use the non-verbose, non-colorized output by default. Maybe even use only the primary rank logs by default (no strong opinion here). However, this is somewhat the default behavior when working with preCICE/adapters/tutorials. We could then still add the CL arguments.

Problem now is which colours to use for the Participants? Are they allowed to clash with the severity levels? Would a bold font be enough?

I guess one would then execute one solver using the colorization and the other without colorization? Or different colors for different participants? I think aste supports only two participants right now. I would just decide for a color, maybe green or blue? I don't think that it will lead to conflicts with other colorization, as the messages are always white (just the severity is colorized).

fsimonis · 2022-09-19T13:07:44Z

Current conclusion is to handle colorization in a future PR.

davidscn · 2022-09-19T13:08:42Z

Last point would be to disable (remove) all logger tags from the preCICE config, right?

fsimonis · 2022-09-19T13:09:30Z

Sure, will do

davidscn · 2022-09-19T13:26:24Z

Considering that the changes here are related to the logging in preCICE, I'm not sure weather we want to add them to the distribution, as the distribution is referring to preCICE v 2.5.0

src/precice-aste-run.cpp

fsimonis · 2022-09-19T14:25:24Z

That's actually a good point. This PR will not work properly until precice/precice#1420 is merged.

* Limit local logging to application log * Indentation using clang-format * Handle log entries from ASTE and preCICE * Hide preCICE log location in non-verbose runs * Add severity and rank filter control * Fix filter expression * Make mapping tester tests verbose * Indentation using clang-format * Remove log sinks from ASTE configuration files * Update flag documentation Co-authored-by: David Schneider <david.schneider@ipvs.uni-stuttgart.de>

fsimonis mentioned this pull request Aug 23, 2022

Improve compatibility with applications using Boost.Log precice/precice#1420

Merged

8 tasks

davidscn force-pushed the extend-local-logging branch from 3ad310f to 0502a2f Compare August 23, 2022 14:55

davidscn reviewed Aug 24, 2022

View reviewed changes

fsimonis changed the title ~~Limit local logging to application log~~ Handle ASTE and preCICE logging Aug 24, 2022

fsimonis force-pushed the extend-local-logging branch from bed3464 to 78df340 Compare September 7, 2022 10:07

fsimonis requested a review from davidscn September 7, 2022 10:19

fsimonis and others added 7 commits September 19, 2022 14:39

Limit local logging to application log

f1fe25f

Indentation using clang-format

761ae3e

Handle log entries from ASTE and preCICE

4f3f26c

Hide preCICE log location in non-verbose runs

18e1910

Add severity and rank filter control

73ce751

Fix filter expression

3f9c4ee

Make mapping tester tests verbose

438c4eb

fsimonis force-pushed the extend-local-logging branch from b5865d8 to 438c4eb Compare September 19, 2022 12:49

Indentation using clang-format

0910718

davidscn reviewed Sep 19, 2022

View reviewed changes

src/precice-aste-run.cpp Show resolved Hide resolved

Remove log sinks from ASTE configuration files

da0cd13

fsimonis and others added 2 commits September 19, 2022 16:26

Update flag documentation

4927bd0

Merge branch 'develop' into extend-local-logging

c10920e

davidscn merged commit 97e2a23 into develop Nov 18, 2022

davidscn deleted the extend-local-logging branch November 18, 2022 13:47

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Handle ASTE and preCICE logging #136

Handle ASTE and preCICE logging #136

fsimonis commented Aug 23, 2022 •

edited

Loading

davidscn commented Aug 23, 2022

fsimonis commented Aug 23, 2022

davidscn left a comment

davidscn Aug 24, 2022

fsimonis Aug 24, 2022 •

edited

Loading

fsimonis commented Aug 24, 2022

fsimonis commented Aug 24, 2022

davidscn commented Aug 26, 2022

fsimonis commented Aug 26, 2022 •

edited

Loading

davidscn commented Aug 31, 2022 •

edited

Loading

fsimonis commented Sep 7, 2022

davidscn commented Sep 19, 2022

fsimonis commented Sep 19, 2022 •

edited

Loading

davidscn commented Sep 19, 2022

fsimonis commented Sep 19, 2022

davidscn commented Sep 19, 2022

fsimonis commented Sep 19, 2022

davidscn commented Sep 19, 2022

fsimonis commented Sep 19, 2022

Handle ASTE and preCICE logging #136

Handle ASTE and preCICE logging #136

Conversation

fsimonis commented Aug 23, 2022 • edited Loading

davidscn commented Aug 23, 2022

fsimonis commented Aug 23, 2022

davidscn left a comment

Choose a reason for hiding this comment

davidscn Aug 24, 2022

Choose a reason for hiding this comment

fsimonis Aug 24, 2022 • edited Loading

Choose a reason for hiding this comment

fsimonis commented Aug 24, 2022

fsimonis commented Aug 24, 2022

davidscn commented Aug 26, 2022

fsimonis commented Aug 26, 2022 • edited Loading

davidscn commented Aug 31, 2022 • edited Loading

fsimonis commented Sep 7, 2022

davidscn commented Sep 19, 2022

fsimonis commented Sep 19, 2022 • edited Loading

davidscn commented Sep 19, 2022

fsimonis commented Sep 19, 2022

davidscn commented Sep 19, 2022

fsimonis commented Sep 19, 2022

davidscn commented Sep 19, 2022

fsimonis commented Sep 19, 2022

fsimonis commented Aug 23, 2022 •

edited

Loading

fsimonis Aug 24, 2022 •

edited

Loading

fsimonis commented Aug 26, 2022 •

edited

Loading

davidscn commented Aug 31, 2022 •

edited

Loading

fsimonis commented Sep 19, 2022 •

edited

Loading