Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Clean up logging #4063

Merged

Conversation

kwvanderlinde
Copy link
Collaborator

@kwvanderlinde kwvanderlinde commented May 14, 2023

Identify the Bug or Feature request

Addresses #4061

Description of the Change

The main goal is to reduce the logging of client-server messages from INFO to DEBUG. That is supported by no longer enabling features based on the current logging level. And finally there is some cleanup to remove unnecessary calls to Logger.isDebugEnabled() by parameterizing our log messages.

Developer Options

This is a new feature that enables toggling secret features in a convenient way, rather than checking the log level or hardcoded flags, and without requiring restarts.

The options are collectively implemented as an enum. Each value of the enum wraps a boolean preference and translated descriptions of the option. Each value is also exposed via the new Developer tab in the Preferences dialog. This is done automatically, so adding new developer options is as simple as adding a value to the enum and then making use of it.

In order to prevent users accidentally leaving these options enabled, or forgetting where to disable them, a warning dialog will be shown when MapTool starts if any developer options are enabled.

Performance timers

Similar to the developer toggles, our colllection and logging of performance also used to be determined by the log level. It was also enabled if the performance windows was opened, which is reflected by AppState.isCollectProfilingData(). We now only rely on this app state, and only report the performance data via the performance window. There is no separate developer option for enabling this.

Conditional logging

In many places we followed a pattern of only invoking Logger.debug() if debug logging is enabled (the same pattern was also sometimes followed for other log levels). Now we prefer to use parameterized logging, so we can still avoid the overhead of building the strings when not enabled, but without needing these checks everywhere. There are a few places remaining where we do the check, but those are cases where further steps are required to produce the message parameters.

Possible Drawbacks

Folks who want the messaging INFOs will now need to sift through DEBUG lines as well.

Documentation Notes

If debugging or developing MapTool, it may be useful to enable certain developer options. These are not meant for normal use, and may have unintended side effects! The options can be found in the Developer tab of the Preferences dialog:
image
When an option is enabled, the corresponding behaviour will be activated immediately, and will persist across restarts. To disable them, just uncheck the checkbox.

If any developer options have been left enabled, a warning dialog will be shown the next time MapTool is opened:
image
This way no one should forget that they have enabled the options, nor will they be confused about where to find them.

Release Notes

  • Reduce the number of INFO logs
  • Add new developer options for toggling developer-centric features.

This change is Reviewable

Calls to `Logger.isDebugEnabled()`, `Logger.isInfoEnabled()`, and `Logger.isTraceEnabled()` have been removed when they
simply gate a simple string log message, or a log message that could be parameterized.

There are a few instances left where we check prior to logging, specificaly if the thing we want to log is not readily
available and has some overhead in computing it. There are also some cases where `isDebugEnabled()` specifically is used
to enable secret features, and those uses still exist.
For some reason calls to `log.error()` were being gated by `log.isDebugEnabled()`. This has been changed to not gate the
messages at all. The first of the three messages has also been reduced to a WARN since it does not indicate a MapTool
error, but a user-provided error.
Actually based on the corresponding `AppState.isCollectingProfilingData()`. No longer do we check if debug logging is
enabled, nor do we write DEBUG logs for timers. Instead we only output to the performance window, which can be readily
accessed in those cases that it is needed.
A new tab was added to the Preferences dialog that allows users to toggle developer features. These come with a warning
in the Preferences dialog since they are not intended to be used in typical situations. If the user leaves any options
enabled, they will also be shown a warning dialog the next time they start MapTool, so that they do not forget about the
enabled options or how to disable them.

The implementation is provided by a `DeveloperOptions.Toggle` enum that contains the four current developer
options. Each option wraps a `boolean` preference, allowing to get and set them, and provides translated labels and
descriptions for each. The enclosing class `DeveloperPreferences` provides a moethd to get all enabled options, which is
used to generate a warning to users. Every member of the enum is also automatically added to the Developer preferences
tab.

These are the four feature that used to be gated in `isDebugEnabled()`:
- `AutoSaveMeasuredInSeconds` to reinterpret the auto-save time as seconds instead of minutes
- `ShowPartitionDrawableBoundaries` to render spatial partition boundaries when rendering drawables
- `ShowAiDebugging` to show details on the A* algorithm
- `IgnoreGridShapeCache` to always recompute grid shapes whenever requested.

Meanwhile, `AbstractAStarWalker` has been reworked with regards to its debug labels, so that it clears only debug labels
instead of all labels. This is more important now that the option can be toggled without a restart.
Any place that merely logged the client-server messages has been reduced from INFO to DEBUG. Logs of other severities
have not been changed.
@cwisniew cwisniew added this pull request to the merge queue May 16, 2023
Merged via the queue into RPTools:develop with commit 3d4a679 May 16, 2023
@kwvanderlinde kwvanderlinde deleted the experiment/reduce-connection-logging branch May 16, 2023 16:42
@cwisniew cwisniew added the bug label Jun 11, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
Status: Merged
Development

Successfully merging this pull request may close these issues.

2 participants