Consider improving how mods write messages to the console and file.

Current system

Usage

Mods log messages by calling static methods on the Log class:

Example console output

[19:10:16] Lookup Anything checking for update... no update available.
[19:10:16] Chests Anywhere checking for update... no update available.
[19:10:18] [19:10:18.1149][EntoaroxFramework/DEBUG] Initializing TypeRegistry functionality...
[19:10:22] [19:10:22.7905][EntoaroxFramework/DEBUG] Initializing ContentRegistry functionality...
[19:10:39] [19:10:39.9644][VersionChecker/INFO] Performing version checks for registered mods...
[19:10:40] [19:10:40.1064][VersionChecker/DEBUG] You are using the latest version of the `EntoaroxFramework` mod available
[19:10:40] [19:10:40.1064][VersionChecker/INFO] Finished checking for updates
[19:10:40] [19:10:40.1144][EntoaroxFramework/DEBUG] Overriding greenhouse teleportation...
[19:10:40] [19:10:40.1149][EntoaroxFramework/TRACE] Attempting to find the greenhouse exit...
[19:10:40] [19:10:40.1149][EntoaroxFramework/TRACE] Greenhouse exit found and hooked into

Pros & cons

• Advantages:
  • ✓ Existing mods already use it.
  • ✓ It's well-tested, since it's been in use for several months now.
• Disadvantages:
  • ✘ The public interface is complex (16 public methods).
  • ✘ Log order isn't guaranteed, which can be very confusing when troubleshooting.
  • ✘ Many of the methods are not semantic — i.e. the mod controls the presentation instead of the meaning. This makes consistency very difficult.
  • ✘ It's often unclear which mod logged a given message.
  • ✘ Mods can't log tracing info that's hidden from the user by default. (Tracing info is very useful in debugging user errors, but can quickly overwhelm the console.)
  • ✘ App exceptions are written to a separate log file, which can be confusing.

Here's one possible approach.

Usage

Each mod would receive a log instance with six methods:

Example console output

[19:10:16 DEBUG Lookup Anything] checking for update... none available.
[19:10:16 DEBUG Chests Anywhere] checking for update... none available.
[19:10:18 DEBUG EntoaroxFramework] Initializing TypeRegistry functionality...
[19:10:22 DEBUG EntoaroxFramework] Initializing ContentRegistry functionality...
[19:10:39 DEBUG EntoaroxFramework] Performing version checks for registered mods...
[19:10:40 DEBUG EntoaroxFramework] You are using the latest version available.
[19:10:40 DEBUG EntoaroxFramework] Finished checking for updates
[19:10:40 DEBUG EntoaroxFramework] Overriding greenhouse teleportation...

Pros & cons of proposed system

• Advantages
  • ✓ The interface is simpler (6 public methods).
  • ✓ The methods are semantic — they indicate the message meaning, not its presentation. That means SMAPI can choose its own presentation to promote consistency and readability.
  • ✓ Log order can be guaranteed.
  • ✓ The message source is always clear.
  • ✓ Mods can log trace info which isn't shown to the player by default.
  • ✓ App exceptions are written to the same log file.
• Disadvantages
  • ✘ For backwards compatibility with existing mods, SMAPI would need to support the old system too (and mark it deprecated).

Might I suggest having a generic Log method that lets you define the prefix (DEBUG, etc.) and color (as ConsoleColor) yourself, with ConsoleColor being completely absent meaning it is a file-only log message.
It would be helpful in cases where existing mods are doing something that doesnt fit perfectly in the levels given.

I personally would also like it if "once" versions could be directly available on the class, as sometimes you need to log something only the first time it happens, but creating booleans for every single time that occurs gets bothersome.

@Entoarox The available log severities range from trace (file-only developer info) to alert (highlighted for the user). Could you give an example of a log message that doesn't fit one of these categories?

Encapsulating one-time messages is a good idea, but that should be planned separately from the base logging feature. (For example, we might consider creating a SMAPI-contrib library with a set of useful extensions and features to keep the core API as streamlined as possible.)

Well, I myself like to mess with the color of messages that are in response to commands while still counting them as a certain type of message, as the color is mainly something relevant to the user directly rather then important to the logging.
I also use a FATAL level myself, for the rare errors that identify major problems that need a fix ASAP rather then being a problem that might not immediately be fatal.

Letting SMAPI manage the presentation keeps things readable for the player. While one mod might want to customise its colours, that can conflict with other mods' custom colours. For example, one mod logs its version with a color similar to SMAPI's alerts, which leads to alert fatigue.

Here's one possible palette for reference:

Messages for the player would be info or alert (depending on their importance), and fatal errors would be error. (Ideally errors should be rare; if they happen so often you need to distinguish important errors from routine ones, you should consider lowering the severity of the routine ones to warning instead.)

If you need to further emphasise a fatal error, you could spice up the message portion:

[19:10:40 ERROR EntoaroxFramework] FATAL: everything has gone terribly wrong!
[19:10:40 ERROR EntoaroxFramework] FATAL: I'm so sorry. :(

Keep in mind that I write mods that interact with other mods, because of this I need a way to identify between "Error that I dealt with and am just reporting for the other person" versus "Fatal issue that broke my mod and needs fixing on my end"

It would be the difference between "File X is missing, but no immediate worry, this mod simply wont do anything / Skip the submod that caused the issue" and "File X is missing, continuing to play the game might cause corruption of your save and who knows what else"

In an ideal situation neither would occur of course, but having a clear distinction by "Important but not game-destroying issue" and "Important game-destroying issue" is helpful, and warning always felt more like "Not guaranteed to be but potentially important issue", like a file being missing but that might be the case because you are using the build-in version of the file.

In short, FATAL should be "Pull out all the stops, try and keep stuff from crashing down around us, and lets hope we are on time to prevent the digital apocalypse" versus "Stuff went wrong when it should not and likely crashed your game, but at least nothing important got broken!"

That makes sense. I don't like side-effects in a log method, so how about a broader monitoring class like this instead?

For example, here's how a mod would report a fatal error and exit the game:

monitor.Log($"Serialisation failed: {ex}", LogLevel.Error);
monitor.ExitGameImmediately("exiting game to prevent save corruption");

And here's what the player would see:

As a bonus, it's broad enough to cover future functionality like one-time messages (as you suggested above), error interceptors, deprecation warnings, etc.

I like it! 😄
I would like if you could have the "Game ended" message be "Fatal issue encountered, open log directory now? Y/N" so people do not have to go looking for the directory, they can just press Y to open it, or N to exit without opening the log dir

Sure, though we'll need to figure that one out separately (see #171 and #172).

Here's how a fatal level might look:

)

I'm not entirely sold on having a fatal error level at all, though. To me a fatal error is still an error; if it's really "fatal", then the game should crash immediately after. You shouldn't depend on the player noticing the console when they're in-game, if there's a risk of save corruption and digital apocalypse.

I completely agree with that, but SMAPI completely sandboxes things to the point where anything that happens inside mod code pretty much cant crash the game, having the fatal level in SMAPI itself though, can make it so that once the fatal error is logged, SMAPI can exit the game, and popup a "The game has crashed due to a fatal error, please upload your log to the forums so that this issue can be solved" message, open the log directory for the user, and close itself.

Done in the upcoming 1.1 release. :)