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

[Refactoring]: Clean up our logs #4061

Closed
kwvanderlinde opened this issue May 12, 2023 · 9 comments
Closed

[Refactoring]: Clean up our logs #4061

kwvanderlinde opened this issue May 12, 2023 · 9 comments
Assignees

Comments

@kwvanderlinde
Copy link
Collaborator

Describe the problem

Our logs are really noisy with all the client-server messages being logged as INFO. I don't tend to look at the networking code, so for me this is just noise that obscures the info I am actually looking for.

I wanted to just change these to DEBUG messages, until I realized that it comes with some serious downsides, not least of which is that changing the log level to DEBUG activates secret features that can get in the way of regular debugging.

The improvement you'd like to see

First up, let's stop enabling/changing functionality based on whether the debug logging is enabled. E.g., A* info does not need to be added to the map just because the log level was reduced, and auto-save does not need to be made 60x more frequent. These should be controlled by their own flags/settings/whatever. In a similar vein, CodeTimers do not need to automatically be enabled either since they can be conditionally enabled, viewed via the performance window, and aren't the sort of thing that's very useful to glean from user logs.

On a related note, we don't need to check Logger.isDebugEnabled() prior to logging DEBUG messages. This is done a lot, presumably to avoid overhead when not in use. We can instead use parameterized logging to avoid the overhead of building complete messages that aren't used.

With debug logging carrying less baggage, it will be okay to reduce some INFO logs to DEBUG. E.g., the client-server message logging can almost entirely be reduced to DEBUG instead of INFO.

Expected Benefits

  • During typical development, the console is more likely to show information useful to the developer.
  • When more information is required debugging can be enabled without unexpected side-effects.
  • Code will be cleaner.

Additional Context

No response

@Azhrei
Copy link
Member

Azhrei commented May 13, 2023

These all sound like great ideas. They just take time for someone to do...

These should be controlled by their own flags/settings/whatever.

How do you see this working? Something like a setProperty() method that would apply just to internal options in MT? Would it be usable for existing options that appear in the UI already? Would this be something an annotation could be used for, so that limited code changes would be required?

Feel free to move this to a Discussion page if you deem the discussion not sufficiently on point. :)

@kwvanderlinde
Copy link
Collaborator Author

kwvanderlinde commented May 13, 2023

I see a few possibilities:

  1. Straightforward-but-clunky: keep boolean fields for each special behaviour, harcoded to false. If a developer wants to work on that part of the code and needs the special behaviour, they manually change it to true. All / most of these behaviours are very developer-specific anyways. And we have some precedence for it, e.g., AbstractAStarWalker.debugCosts / ZoneRenderer.showAstarDebugging.
  2. A more user-oriented option: add a tab to the Preferences dialog for "developer" or "debug" options, with checkboxes to enable/disable the special behaviours. Easy to discover, and easy to tell users how to use it if we need to debug something with them.
  3. Command line flags (middle ground): this could be suitable for use with ./gradlew run or if running a .jar directly. It can be done for end users as well, but editing command line options for package installs is more technical.

I'd like to see something along the lines of (2). It would be very convenient, plus a new dev could easily get an idea of just what there is to discover and start tinkering. Downside would be if a user enables a behaviour and then forgets to turn it back off, they may be surprised next time they use MapTool. But that could be mitigated by notifying the user that developer options are in use, and showing them where they can go to disable them.

@kwvanderlinde
Copy link
Collaborator Author

Now I have visuals for (2)!

The idea would be I as a developer might turn on a couple options like this:
image
Unlike the other possibilities, this won't require a restart just to enable them.

But if I leave them enabled and restart MT, I'll be met with a warning about them:
image

@cwisniew
Copy link
Member

Now I have visuals for (2)!

The idea would be I as a developer might turn on a couple options like this: image Unlike the other possibilities, this won't require a restart just to enable them.

But if I leave them enabled and restart MT, I'll be met with a warning about them: image

I prefer option 2, as it will be helpful sometimes to have extra information from users experiencing issues.

1 similar comment
@cwisniew
Copy link
Member

Now I have visuals for (2)!

The idea would be I as a developer might turn on a couple options like this: image Unlike the other possibilities, this won't require a restart just to enable them.

But if I leave them enabled and restart MT, I'll be met with a warning about them: image

I prefer option 2, as it will be helpful sometimes to have extra information from users experiencing issues.

@Azhrei
Copy link
Member

Azhrei commented May 14, 2023

Looks good! Thanks!

Do you plan to generate that tab programmatically? Like having a class register with a DeveloperOptions singleton class that keeps a list of ID strings (for looking up messages and tooltips in a resource bundle) and a reference to an Object (Boolean, most times) where a value will be stored when the user interacts with the GUI? That would allow new features to be added without touching the GUI, and would allow the input to be a checkbox or Integer or String, as needed. Maybe include a listener interface as well?

@kwvanderlinde kwvanderlinde self-assigned this May 14, 2023
@kwvanderlinde
Copy link
Collaborator Author

kwvanderlinde commented May 14, 2023

Do you plan to generate that tab programmatically?

Yes

Like having a class register with a DeveloperOptions singleton class that keeps a list of ID strings (for looking up messages and tooltips in a resource bundle) and a reference to an Object (Boolean, most times) where a value will be stored when the user interacts with the GUI? That would allow new features to be added without touching the GUI, and would allow the input to be a checkbox or Integer or String, as needed.

Along those lines, yes, but for now there is no need for anything complicated. A simple enum will suffice, encapsulating boolean preferences and being exposed as checkboxes in the Preference dialog.

Maybe include a listener interface as well?

Thought about it, but for now it wouldn't actually be useful. Current usage follows a pattern of "check-then-act", so wouldn't benefit from listeners anways. Can always be expanded in the future if needed.

@kwvanderlinde
Copy link
Collaborator Author

Got a couple of reports of dev options being enabled by default. Fix incoming.

@kwvanderlinde kwvanderlinde moved this from Needs Testing to In Progress in MapTool 1.14.0 Oct 19, 2023
@kwvanderlinde kwvanderlinde moved this from In Progress to Needs Testing in MapTool 1.14.0 Oct 19, 2023
@kwvanderlinde
Copy link
Collaborator Author

Closing this off as it's been in the wild for some time with no further issues reported.

@github-project-automation github-project-automation bot moved this from Needs Testing to Done in MapTool 1.14.0 Apr 1, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
Status: Done
Development

No branches or pull requests

3 participants