Issue921

Title add verbosity option to all heuristics/those heuristics that produce lots of output
Priority feature Status reviewing
Superseder Nosy List jendrik, malte, manuel, patfer, silvan
Assigned To silvan Keywords
Optional summary

Created on 2019-06-07.11:28:12 by silvan, last changed by patfer.

Messages
msg9269 (view) Author: silvan Date: 2020-05-05.19:18:24
We decided to proceed as follows:
- issue963 will replace cout by g_log in the planner (including working on the Logger class to recognize endl) 
- issue964 will add an option to use local Logger objects (shared_ptr) and move the current functionality of verbosity levels to the Logger class. Similarly to g_rng, users use the default global logger if not specifying the option.
- this issue: add the logger option instead of the verbosity option to modules that produce lots of output or that should be silenced.
msg9252 (view) Author: jendrik Date: 2020-04-30.15:12:53
Before you make any planner-wide changes (here on in a separate issue), I recommend to comment out most of the files in the CMake file (or use a selective build) and focus on a few example files until we're happy with the design.
msg9246 (view) Author: jendrik Date: 2020-04-22.14:39:06
> Also, how would using g_log work? We would need to have a global verbosity level then.

I think g_log can be removed once we have access to Log objects everywhere.

Regarding issue589: we could eventually add methods to the Log class for structured output such as log.statistics("variables", num_variables);

Regarding prepending the time and memory output: I agree that this should only be done if the user thinks it adds useful information. We could use the following syntax for plain output

if (log.is_verbose())
    log << "Variables: " << num_variables << endl;

and for prepending time and memory usage:

if (log.is_verbose())
    log.resources << "Variables: " << num_variables << endl;

(For this the Log::resources member would simply be an instance of the current Log class, which we could encapsulate in the new Log class.)
msg9245 (view) Author: malte Date: 2020-04-22.11:26:17
I think always going through a logger would be good practice, and we can discuss which output the logger should make. We should be clear about the different logging use cases, and that having parsable statistics is only one of them. So I agree a greater discussion of this would be useful.

I agree with Silvan's comment that I would not use "log" to check verbosity, but then use another mechanism (cout) for the actual output. I think that mixes responsibilities and loses much of the benefit of using a logger (e.g. being able to control where the logging ends up, and in which format the output is printed).
msg9244 (view) Author: silvan Date: 2020-04-22.11:18:08
I don't like this suggestion too much because it requires using a Log object everywhere I want to have (controlled) output. I know that the cegar code extensively (exclusively?) uses the Log class to output progress (more precisely: g_log), but I'm not a fan of reading [t = ..., ... KB] prepended to all of my output mostly because I'm using my own timers, and therefore I never use Log. Looking at the users of g_log/Log, I see that actually *only* the cegar code uses it :-) So yes, we should definitely consolidate our logging mechanisms.

Your suggestion to add Verbosity to Log would still not convince me to use it, because I find your suggested solution of using 
if (log.is_verbose())
    cout << "Variables: " << num_variables << endl;
to avoid [t=...] not ideal as this means to only use log for asking for the verbosity level, which is the same as storing Verbosity instead of Log in my class. Also, how would using g_log work? We would need to have a global verbosity level then.

However, if using Log really helps towards issue589, then I'm more willing to use that class. But in its current form, I don't see how it helps: wasn't the idea for automatically parsing statistics to use a unique form of output? I'm totally fine with using a dedicated Log class for such special-purpose output, but most of my output is not related to statistics (and should not be parsed), but to progress, and I would prefer to keep it to a simple cout.

I think we need to discuss this in more detail to make a good decision.
msg9243 (view) Author: jendrik Date: 2020-04-22.00:11:17
The changes look fine to me.

Looking at the patch as a whole again, however, I'm not sure if we shouldn't be moving in a slightly different direction. We're currently passing around the Verbosity enum to control the logging output. Wouldn't a dedicated logging object be more suited for the task? Such an object could hold the Verbosity enum and the code could look roughly the same as it does now, except that we query Log::verbosity instead of querying the Verbosity enum directly.

So instead of

if (verbosity >= utils::Verbosity::VERBOSE)
    cout << "Variables: " << num_variables << endl;

we would write

if (log.verbosity >= utils::Verbosity::VERBOSE)
    cout << "Variables: " << num_variables << endl;

and we could add helper methods to reduce the boilerplate code

if (log.is_verbose())
    cout << "Variables: " << num_variables << endl;

If we decide to add the Verbosity enum to the existing utils::Log class, users could even decide on a case-by-case basis whether to also log the time and peak memory usage for their log messages by using "log" instead of "cout":

if (log.is_verbose())
    log << "Variables: " << num_variables << endl;

Having access to a dedicated logging object instead of the enum would also make extending our logging mechanism easier in the future. For example, it would simplify adding more structured statistics output (issue589).
msg9239 (view) Author: silvan Date: 2020-04-21.18:17:43
I did another iteration, adding the option to the landmark code and changing the meaning of "silent" to actually not output anything at all (in the module in question).
msg9224 (view) Author: jendrik Date: 2020-04-16.18:24:15
I left two comments on Bitbucket.
msg9222 (view) Author: silvan Date: 2020-04-16.17:52:25
Any news on that front? :-) I think all that would need to be done is that you, Jendrik, would check if my last commits addressed your comments.
msg9203 (view) Author: silvan Date: 2020-02-17.12:28:50
I addressed them and also addressed my own comments on Manuel's code, since these were not yet taken care of. I created a new pull request because I don't have writing rights on Manuel's repo:
https://bitbucket.org/SilvanS/fd-dev/pull-requests/55/issue921/diff
msg9202 (view) Author: jendrik Date: 2020-02-14.18:24:44
Sure, I left some comments.
msg9201 (view) Author: silvan Date: 2020-02-14.17:44:10
I think merging this issue is low-effort; Jendrik, could you maybe have a look if the levels of verbosity make sense for CEGAR?
msg8898 (view) Author: silvan Date: 2019-06-14.10:37:23
Thanks! I left a few more comments on the diff. Jendrik, I'll leave thinking
about levels of the CEGAR output to you :-)
msg8894 (view) Author: manuel Date: 2019-06-13.11:07:58
Here are the outputs of the different configurations.
I think providing the output is better than providing the pairwise diffs.

http://ai.cs.unibas.ch/_tmp_files/heusner/ipdb-verbose.log
http://ai.cs.unibas.ch/_tmp_files/heusner/ipdb-normal.log
http://ai.cs.unibas.ch/_tmp_files/heusner/ipdb-silent.log

http://ai.cs.unibas.ch/_tmp_files/heusner/cegar-debug.log
http://ai.cs.unibas.ch/_tmp_files/heusner/cegar-verbose.log
http://ai.cs.unibas.ch/_tmp_files/heusner/cegar-normal.log
http://ai.cs.unibas.ch/_tmp_files/heusner/cegar-silent.log

http://ai.cs.unibas.ch/_tmp_files/heusner/diverse_potentials-verbose.log
http://ai.cs.unibas.ch/_tmp_files/heusner/diverse_potentials-normal.log
http://ai.cs.unibas.ch/_tmp_files/heusner/diverse_potentials-silent.log
msg8890 (view) Author: silvan Date: 2019-06-12.17:51:31
I added some initial comments.

I think that generally we want the verbosity option on the level of Heuristic
(possibly even Evaluator at some point). All heuristics not "supporting" that
option could document this. This way, the "add_verbosity_options..." could be
added once in the "add_heuristic_options...".

Also, some decisions regarding using VERBOSE or NORMAL seem a bit arbitrary at
this point. Furthermore, it is hard to make sure that each possible output is
guarded or was considered to be guarded by the verbosity level in case if it
should always be printed. I therefore suggest that you produce three diffs of
log files for affected configurations, so that we can discuss what should be
printed and what shouldn't at different levels.
msg8889 (view) Author: manuel Date: 2019-06-12.17:34:24
I added the verbosity option to the ipdb, cegar and diverse_potentials
heuristics. These were the three heuristics which produced the largest output in
issue744 (besides of to merge_and_shrink).

Here is the pull request:
https://bitbucket.org/manuel_h/downward/pull-requests/7/issue921/diff

It remains to discuss whether we want to provide the option to all heuristics.

Another issue is that for example cegar uses a landmark factory which produces
its own output. To control the output of a landmark factory, we would need the
verbosity option for landmark factories as well. Compared to the output of some
heuristics, the output of landmark factories is negligible.
msg8863 (view) Author: silvan Date: 2019-06-07.11:33:38
*now
msg8860 (view) Author: silvan Date: 2019-06-07.11:28:12
In issue744, we used the verbosity option from M&S for the search engines to be
able to reduce output during search. Some heuristics also produce lots of
output, e.g., iPDB or more generally, heuristics with a precomputation phase.
Adding support for the verbosity levels we know have for such heuristics should
be easy. We need to discuss if we want to use this feature for all heuristics or
rather only for some selected ones.
History
Date User Action Args
2020-05-06 08:24:15patfersetnosy: + patfer
2020-05-05 19:18:24silvansetmessages: + msg9269
2020-04-30 15:12:54jendriksetmessages: + msg9252
2020-04-22 14:39:06jendriksetmessages: + msg9246
2020-04-22 11:26:17maltesetmessages: + msg9245
2020-04-22 11:18:08silvansetmessages: + msg9244
2020-04-22 00:11:17jendriksetmessages: + msg9243
2020-04-21 18:17:43silvansetmessages: + msg9239
2020-04-16 18:24:15jendriksetmessages: + msg9224
2020-04-16 17:52:25silvansetmessages: + msg9222
2020-02-17 12:28:51silvansetstatus: chatting -> reviewing
assignedto: manuel -> silvan
messages: + msg9203
2020-02-14 18:24:44jendriksetmessages: + msg9202
2020-02-14 17:44:10silvansetmessages: + msg9201
2019-06-14 10:37:23silvansetmessages: + msg8898
2019-06-13 11:07:58manuelsetmessages: + msg8894
2019-06-12 17:51:31silvansetmessages: + msg8890
2019-06-12 17:34:24manuelsetmessages: + msg8889
2019-06-12 14:22:30manuelsetnosy: + manuel
assignedto: manuel
2019-06-07 11:33:38silvansetpriority: wish -> feature
status: unread -> chatting
messages: + msg8863
2019-06-07 11:28:12silvancreate