[LOG] Set default log level to 'debug'

[tobous]

Sets the default log level to 'debug'. For most development or even
debugging tasks, the 'trace' log level should not be necessary. It
provides very detailed information for many background processes that
often aren't of interest. This floods the logs with way too many
messages to properly discern the important information.

If the 'trace' level is actually needed, it can still be set manually be
the developer.

[Drakulix]

We probably should have done this way sooner.
I am all for it.

But maybe we should add a note about the default and how to change it to trace to
https://www.saros-project.org/contribute/logging.html ?

[tobous]

After reading the page, I am a bit confused which configuration is actually used. Because the logic that sets up the logging in Saros/E and Saros/I actually specifies the log level as well. It seems to use the stricter of the two log levels. So leaving the implementations as 'ALL' and just specifying the wanted minimal log level in the xml config should work. It still seems weird to me.

@m273d15 Any comments on the behavior?

Additionally, Saros/E has a separate log4j configuration XML and Saros/I does not. (The Saros/E configuration file is already set to 'debug' by default.) But this is something that students are currently working on if I remember correctly, isn't it?

[Drakulix]

Additionally, Saros/E has a separate log4j configuration XML and Saros/I does not. (The Saros/E configuration file is already set to 'debug' by default.) But this is something that students are currently working on if I remember correctly, isn't it?

It was supposed to become easier after the work that lead to #1124 was done. The original proposal of @m273d15 imagined something like a log4j-Bundle. But I do not think that this PR is attempting to solve the log4j problem itself.

[tobous]

Adjusted the Logging page.

[srossbach]

The TRACE log level was (is?) only used if you start the STF launch configuration. I do not know how IntelliJ setup things but it is really necessary to touch the configuration files when you can do most stuff via coding ?

[tobous]

The Saros/E configuration file is already set to 'debug' by default.

I was working under wrong assumptions when saying that Saros/E currently has a configuration file that is set up for debug. The Saros/E-specific log4j configuration is copied from the main configuration when running the prepareEclipse task and is ignored by Git. The file was still present from a previous build which had the debug log level. When re-generating the file now, Eclipse is also set up with log level all.

The TRACE log level was (is?) only used if you start the STF launch configuration. I do not know how IntelliJ setup things but it is really necessary to touch the configuration files when you can do most stuff via coding?

With the current setup on master, Saros/E runs with the log level all. If this is not the case, you will probably have to delete and re-generate the Saros/E-specific saros_log4j2.xml.

As mentioned above, the log level can be set in two places: The central configuration file for log4j or the implementation-specific logic loading the logger. On the current master, all of these are set up with the log level all for development setups (or info/warn for releases/when the saros.debug env variable is not set; the variable is set by default by the different Jobs to run Saros during development, like the STF launch configurations). See central configuration, Saros/E annotation loading, and Saros/I annotation loading.

I am not sure what you mean by "do most stuff in coding". Could you be more specific?

In general, I would prefer setting the wanted default log level in the global configuration instead of for each component separately. And in the rare case where a developer wants to enable trace logging for local tests, doing so in the global configuration instead of the implementation-specific code is the right approach as well in my opinion.

The only remaining outlier is the STF. If we wan't to run it at a trace log level, I would suggest adding a specific configuration to the STF and not the other way around. In general, I would guess that the logs of actual STF runs aren't looked at very often. It is much more common to test Saros locally in a development setup (using the STF launch configuration or the runIDE command for Saros/I). And for such cases, trace log level is very annoying. Even for STF runs, I am not sure what benefit trace logging provides.

[srossbach]

What is the problem running the STF with trace mode ? You can spot the start and ending in the log files. Again what is wrong with trace mode when running the application in test mode ? As for the log files, it really does not matter if you use debug or trace as most people does not even have a clue what is going on when reading the log. Seriously, just grab an editor an just filter the trace statements out (should not be that hard).

Default level should be INFO, WARNING, ERROR, FATAL. If you need to write code in the application to change it, then yes please apply a patch and ensure that other levels are enabled only if you are running Saros in development environment.

[tobous]

What is the problem running the STF with trace mode ? You can spot the start and ending in the log files. Again what is wrong with trace mode when running the application in test mode ? As for the log files, it really does not matter if you use debug or trace as most people does not even have a clue what is going on when reading the log. Seriously, just grab an editor an just filter the trace statements out (should not be that hard).

I don't have an issue with running the STF in TRACE mode, I just meant we shouldn't sacrifice the development/debugging workflow for it.

To get more concrete, I have an issue with using the TRACE log level when debugging Saros/I. I am already using a plugin to automatically hide TRACE lines in the console output, but the console buffer is limited. The TRACE log level causes such an enormous amount of messages that the log gets truncated relatively quickly, meaning I have to open the log files in a separate editor to get an overview. This makes debugging difficult, especially when testing something in a longer session. I already increased the console buffer size to 4mb, but it is still not enough. And increasing the buffer size further just moves the problem. The same issue applies to the Eclipse console output during debugging.

That is why I was saying that, in my opinion, trace logging is not the best option for debugging/testing in most cases. It just makes the process slower/more cumbersome without providing much additional value.

Default level should be INFO, WARNING, ERROR, FATAL. If you need to write code in the application to change it, then yes please apply a patch and ensure that other levels are enabled only if you are running Saros in development environment.

That is already the case. Maybe my previous statement was not as clear as I thought. In general, the default log level for Saros/E is WARN and the default log level for Saros/I is INFO. (If you would like, I can include the change to make INFO the default log level for Saros/E in this PR as well.) Only when the saros.debug environment variable is set to true, which is the case for the STF launch configurations as well as the default task to run Saros/I for local debugging, is a broader log level used.

Currently, this broader log level is ALL. As mentioned above, I would like it to be DEBUG instead to make debugging during the development process easier. This would make it more difficult to still use TRACE logging for STF runs as the more strict log level is used when the xml file and implementation-specific settings vary as far as I can tell. I would have to think some more on this issue to propose a proper solution.

[srossbach]

I got your problem which simply relies on the fact that the network layer "spams" the logfile for every packet,

My simple proposal (at least for Saros/E), in production mode FATAL, ERROR, WARN, INFO, normal startup +DEBUG and running the STF +trace.

So just ensure that the default level does not include DEBUG or everything more detailed. The rest should be done via coding.

If this is already the case for this patch then you are free to merge it.

[tobous]

So just ensure that the default level does not include DEBUG or everything more detailed. The rest should be done via coding.

I am still not sure what you mean by should be done via coding. Could you elaborate? Do you mean that the settings should be adjusted in the IDE-implementation-specific logic loading the logging settings?

[srossbach]

So just ensure that the default level does not include DEBUG or everything more detailed. The rest should be done via coding.

I am still not sure what you mean by should be done via coding. Could you elaborate? Do you mean that the settings should be adjusted in the IDE-implementation-specific logic loading the logging settings?

https://github.com/saros-project/saros/blob/master/eclipse/src/saros/Saros.java#L265

How is it done in IntelliJ ?

[tobous]

So just ensure that the default level does not include DEBUG or everything more detailed. The rest should be done via coding.

I am still not sure what you mean by should be done via coding. Could you elaborate? Do you mean that the settings should be adjusted in the IDE-implementation-specific logic loading the logging settings?

https://github.com/saros-project/saros/blob/master/eclipse/src/saros/Saros.java#L265

How is it done in IntelliJ ?

Ok, so we are talking about the same thing. In IntelliJ, the logic is basically the same (with the exception that the base log level in production is INFO): https://github.com/saros-project/saros/blob/master/intellij/src/saros/intellij/SarosComponent.java#L62

It just seems weird to me to have a setup in the log4j2 configuration file that is basically ignored as the real rules are set up separately by each Saros implementation. This makes it much harder to actually understand the used log level.

This is made more complicated by the fact that the configurations don't seem to actually overload each other but rather the more strict log level of the two configurations seems to be used (i.e. it does not matter whether I set the file to ALL and the logic to WARN or the file to WARN and the logic to ALL, the WARN log level is used either way).

[srossbach]

Well we could make many guesses or @m273d15 could simply explain his intentions.

But if you say that the more restrictive level is taken anyways then there is really no choice beside setting the default log level to trace in the configuration file. Or it is an issue in our coding. I do not know it.

[FelixSelter]

Everything properly formatted etc.
Nothing changing the actual code so fully compatible.

I can't really review if this makes sense but the intention mentioned sounds logical and would increase efficiency