Issue964

Title Add option to use a local logger instead of the global one
Priority feature Status in-progress
Superseder Nosy List jendrik, malte, patfer, silvan
Assigned To silvan Keywords
Optional summary

Created on 2020-05-05.19:17:39 by silvan, last changed by malte.

Messages
msg9353 (view) Author: malte Date: 2020-06-10.13:54:06
Sure, let us schedule a discussion. Are you 
available later today? When? That CEGAR 
creates a heuristic object for this is a 
design flaw that we already knew but deferred 
addressing and already bit us in other ways, 
so perhaps now is the time to address this. 
This is really an instance of the same thing.
msg9352 (view) Author: silvan Date: 2020-06-10.13:14:29
TransitionSystem objects are created within a factored transition system or by the MIASM merge strategy when it copies existing factors to temporally compute products. In both cases, they are not created from command line and therefore would need to have a log passed from elsewhere to store the log in the class (btw. LogProxy also has a boolean "line_has_started"). The only way I see how this would work is to configure the log of the merge strategy to be silent. Of course this would silence all of its output, including for example the dumping of its options which the merge-and-shrink algorithm normally does at the start.

For CEGAR, the situation could not be easily repaired this way: the h^add heuristic would be created from a manually created options object. If we use the log that CEGAR has (because it is being created from command line), then we could either silence the entire CEGAR code or nothing, but not just the "initializing h^add heuristic..." which is what we want (or at least I want :-) ).

Maybe it is better to schedule a discussion indeed before spending more time writing? We can also come back to the scheduling of such a discussion in a few days if you don't want to plan anything right now.
msg9351 (view) Author: malte Date: 2020-06-10.12:55:11
We discussed eventually having LogProxy in a common base class used by all plugin-created classes (we really need a word for these classes...), so I think we'll move towards having a log available in such classes anyway. (Assuming they are command-line-configured, which I think the classes you mention are.) Perhaps this can inform the direction that we'll follow for now. It only costs one pointer, so it's not a significant cost.

Does this help for the next steps? Otherwise, we can schedule a discussion.
msg9350 (view) Author: silvan Date: 2020-06-10.12:42:13
In the case of M&S (and many other places), I thought it would be better/easier to not store a logger in each class, but rather pass it to the methods which need it. For functions, this needs to be done anyway, and in the M&S scenario, the use case is that there is a common utility function for shrinking which uses the mentioned method. This function needs a log to be passed in.

I'm happy to have a live discussion about this if you can find the time for it; otherwise, this can wait.
msg9349 (view) Author: malte Date: 2020-06-10.11:57:48
I am not sure how well I can articulate this in a brief message, perhaps it's best to leave this for a later live discussion, perhaps also in the context of the code (which I cannot check right now, but let me know if you would like me to have a look as a priority).

It's mainly about the level of granularity at which behaviour is configured. If it's the whole class that is to be silenced, passing a silent logger to its constructor is an accepted code practice. If loggers are created and used at a much finer level of granularity, I would generally say that something might be off with the level of abstraction at which the output is controlled. The two cases you mention sound like it would be best to pass a silent logger to the constructor of these classes, and then the functions would not need anything passed in. But I haven't had a look at the code.
msg9348 (view) Author: silvan Date: 2020-06-10.11:37:40
I don't understand. I thought the idea of having a verbosity level (or more generally, a configurable log) as a parameter for some function would be useful, among others, for exactly the use case of using the function with different verbosity levels. The function always "logs", but if the verbosity level of the log is silent, then it doesn't print anything.

The concrete use case is the method TransitionSystem::apply_abstraction: during the merge-and-shrink algorithm, we use the log of the algorithm to log the output of this method. However, the "score-based MIASM" strategy repeatedly copies transition systems and shrinks them, and at this point, we would like to use different log level. Another use case (part of issue961) will be CEGAR which repeatedly constructs h^add heuristic objects which produces lots of output which could be silenced.
msg9347 (view) Author: malte Date: 2020-06-10.11:22:17
I don't think this is good design. Log classes are meant to implement user-controllable output preferences, not control flow, i.e., functions that sometimes log and sometimes don't. It's best not to mix the two things (i.e., output suppressed because it was configured that way vs. something that should not output because of control logic).

In a normal case, I think the best option would be not to have logging be conditional. This may require some other code changes; it would be good to look at some specific cases that use this pattern currently.

If the first option doesn't work out and logging has to be conditional, I would add an explicit parameter flag such as "enable_logging" or "disable_logging" or "silent" or whatever to the function and test that instead. Hopefully you would not have to also pass in a logger because the logger is already stored in the instance.

In the third case, if we have to go down the path of specialized loggers instantiated from code, rather than adding special-purpose utility method like this, it may be a better idea would be to make the constructor of LogProxy more convenient so that we can write

  LogProxy(args...)

for

  LogProxy(make_shared<utils::Log>(args...))

in general. This is not difficult to do in C++11 with a variadic template constructor using perfect forwarding. (I would make the constructor explicit.)

But I would see it as a priority order: I would look at the first option first, then the second if necessary, then the third if necessary.
msg9346 (view) Author: silvan Date: 2020-06-10.10:42:04
Sounds like a good idea, although we might need more and more of such special default loggers if we later add more option. But for the moment, I'd go with this suggestion.
msg9345 (view) Author: patfer Date: 2020-06-10.10:41:07
Can we simply add a method to logging.h which returns a new silent LogProxy. This hides the class Log and would be shorter (utils::make_silent_log()).
msg9344 (view) Author: silvan Date: 2020-06-10.10:11:51
Something which came up when propagating the new Log class through merge-and-shrink is that we now have to write

utils::LogProxy log(make_shared<utils::Log>(utils::Verbosity::SILENT));

if we want to use some function which we would like to silent. This is quite long (but still ok in my opinion), but it also means that we must continue to expose Log (in addition to LogProxy) in logging.h. Are we fine with this or does someone has a better idea of how to silence a method? (Previously, we would just pass utils::Verbosity::SILENT.)
msg9342 (view) Author: malte Date: 2020-06-08.19:28:47
get_stream would return a reference, not a copy. But we don't need it for now, so feel free to leave as is. Code looks good to me. (I already had a look before your message.)
msg9341 (view) Author: silvan Date: 2020-06-08.19:27:52
I added LogProxy and reduced the functionality of Log to be a wrapper for Verbosity. ostream cannot be copy-constructed so I didn't know how to implement the get_stream method which you suggested.
msg9340 (view) Author: malte Date: 2020-06-08.15:00:36
The main thing that bothered me about the proxy solution is the duplication of methods, but I now realized that such a duplication is not actually necessary: it is enough to implement the methods on the proxy, and the "actual" Log object only needs to contain enough information to allow implementing the proxy. (For example, something like a get_verbosity() method and a get_stream() method, where get_stream() currently just returns cout.) This is essentially how the pImpl idiom works, and how our abstract tasks already work. The proxy class would essentially implement the public interface of the log, and the internal class that it wraps would essentially implement the private interface. Since it's a common recommendation that the private interface should not depend on the public interface, that doesn't actually sound like it should cause any design or duplication issues.
msg9339 (view) Author: silvan Date: 2020-06-08.14:53:40
You're right; I oversaw that in the current implementation, a *copy* would be created instead of returning a reference/pointer to the global log object. So yes, there is no way around it.
msg9338 (view) Author: malte Date: 2020-06-08.14:50:35
I don't understand. It indeed sounds analogous to the RNG case to me, and there we need to store a shared_ptr<utils::RandomNumberGenerator> to refer to the RNG because it can either be a newly created object or the shared global RNG.

If we sometimes return an existing object to be used in other contexts and sometimes create a new instance, like you describe, we need a shared pointer and have the "(*log) << ..." issue that we discussed.

I think you're mainly thinking of the question whether "Log" is a "first-class" plug-in object, i.e., a plug-in type on the command line, with its own doc page, etc. That's indeed not the case, but that's not why we need the proxy.
msg9337 (view) Author: silvan Date: 2020-06-08.13:43:46
In contrast to what we discussed today, at the moment, we actually wouldn't need a wrapper class such as LogProxy to wrap the actual Log because we don't create the Log objects from command line. Currently, there is only one option for Log, which is Verbosity, and "add_log_options_to_parser" simply adds the Verbosity option. Then, if Verbosity==Normal, we just return g_log and otherwise create a new Log instance. This is in analogy to Rng which depends on its only option "seed".

If we expect to have more options for Log in the future, then it might be worth turning Log into a plugin and creating it from command line, but I actually wouldn't advocate for it. (It would mean to have an "option" called log which could be used with only one choice because we won't have different Log classes.)
msg9335 (view) Author: silvan Date: 2020-05-25.15:48:01
Yes, maybe we can have a quick live chat on this tomorrow morning. Regarding the names, it seems to be really hard to come up with something short and yet better suited.
msg9334 (view) Author: malte Date: 2020-05-25.13:46:18
The pull request looks good to me, modulo naming of methods. I left a comment on this on bitbucket. I'm not sure I fully understand the discussion, perhaps best to move it to live?
msg9333 (view) Author: patfer Date: 2020-05-25.10:58:59
I had the same initial though as Malte with the base classes. Adding to each class the same code to handle the loggers is 1. annoying, and 2. ugly to maintain,
-> I vote for a common base class for configurable objects

If we use a base class to handle the logger code, then every class should use its own logger variable (if that is the same as g_log, then be it).
msg9331 (view) Author: silvan Date: 2020-05-23.17:02:42
I didn't suggest to not store the log. The question I rather wanted to ask is whether you think it is okay that classes who don't want to get a specialized Log object continue to use g_log rather than using the helper methods to retrieve their "own" Log object, which would be a pointer to g_log in this case anyway.
msg9330 (view) Author: malte Date: 2020-05-21.16:32:14
If we don't store the log, don't we need to store an Options object instead? That seems roughly similar in code complexity. Ceteris paribus, I would prefer a solution where we don't call get_log_from_options repeatedly because it seems less future-proof (some things should logically happen when the log object is created/destroyed, so we might want to have a handle on its lifetime) and less in line with how we do things for other objects configured on the command line.

I've thought before that we might want to have a common base class for objects configured from the command line. Then common handling of the log could be handled by the base class. This is something I would like to consider when we move forward on the "command-line parsing creates factories rather than the final objects" idea.
msg9329 (view) Author: silvan Date: 2020-05-21.11:37:49
I started working on this. When we discussed this step, we thought it would be a good idea to have the same logic as we use for creating rng objects:
- use function add_log_options_to_parser(parser)
- use function get_log_from_options(options) to retrieve the Log object, which would default to g_log if the options specific to Log would not be present in options (i.e., add_log_options_to_parser has not been called) or to a newly created Log.

The disadvantage I see with this is that *all* classes that currently produce output (= use g_log) would need to call "get_log_from_options" and to store a copy (pointer) of g_log. My first attempt to implement this for merge-and-shrink instead opts for the simpler solution where get_log_from_options always returns a new object. This method should only be used by classes which wish to have their own Log object, and they should call add_log_options_to_parser before. One disadvantage is that g_log would still be exposed (and created with a non-configurable normal verbosity level) and could accidentally be used instead of a local Log object.

Independently of the above design question, I added a verbosity level to the Log class. I'm not happy with the current methods is_normal, is_verbose etc. of Log.

Happy to here your thoughts: https://bitbucket.org/SilvanS/fd-dev/pull-requests/58/issue964/diff
msg9268 (view) Author: silvan Date: 2020-05-05.19:17:39
Once issue963 is done, we want to allow modules to use local logger objects, configured to their needs, instead of the global one. In particular, the existing verbosity option should become part of the logger class.
History
Date User Action Args
2020-06-10 13:54:06maltesetmessages: + msg9353
2020-06-10 13:14:29silvansetmessages: + msg9352
2020-06-10 12:55:11maltesetmessages: + msg9351
2020-06-10 12:42:13silvansetmessages: + msg9350
2020-06-10 11:57:48maltesetmessages: + msg9349
2020-06-10 11:37:40silvansetmessages: + msg9348
2020-06-10 11:22:17maltesetmessages: + msg9347
2020-06-10 10:42:04silvansetmessages: + msg9346
2020-06-10 10:41:07patfersetmessages: + msg9345
2020-06-10 10:11:51silvansetmessages: + msg9344
2020-06-08 19:28:47maltesetmessages: + msg9342
2020-06-08 19:27:52silvansetmessages: + msg9341
2020-06-08 15:00:36maltesetmessages: + msg9340
2020-06-08 14:53:40silvansetmessages: + msg9339
2020-06-08 14:50:35maltesetmessages: + msg9338
2020-06-08 13:43:46silvansetmessages: + msg9337
2020-05-25 15:48:01silvansetmessages: + msg9335
2020-05-25 13:46:18maltesetmessages: + msg9334
2020-05-25 10:58:59patfersetmessages: + msg9333
2020-05-23 17:02:43silvansetmessages: + msg9331
2020-05-21 16:32:14maltesetmessages: + msg9330
2020-05-21 11:37:49silvansetstatus: chatting -> in-progress
messages: + msg9329
2020-05-21 10:08:25silvansettitle: Add option to use a global logger instead of the global one -> Add option to use a local logger instead of the global one
2020-05-06 08:23:16patfersetnosy: + patfer
2020-05-05 19:17:39silvancreate