Logs changes

[KABoissonneault]

This is my last DFU 1.1 item and the more controversial one, and the one I'm most willing to budge on.

In addition to log reachability (addressed by #2606), I have determined three issues with the default Unity logs.

1. They are extremely noisy. Each line has this appended (Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 39) and an extra newline, making logs extremely long and hard to get through
2. There is nothing indicating a normal log from a warning from an error, unless the message repeats that information
3. We cannot relocate the logs to a folder other than Application.persistentDataPath. This is an issue for Allow Portable Installs #2556

So this changelist aims to make going through user issues easier, and unblocking the Portable Install feature. But it is not without downsides unfortunately.

Concretely, what this changelist does is disable Unity's Player.log, and adds a log handler to the Debug class to create and manage this file ourselves. Doing so is mostly necessary for point 3, we could get the benefits of point 1 and 2 by simply creating a second log file, and leave the normal Unity Player.log untouched. We'll see the downsides of supporting point 3 below.

First, here's what the old logs look like

Here's what they look like now

Errors and warnings are shown with a little tag

This token is both searchable and can be parsed by code. I saw someone claim they were working on a log viewer for DFU, and this could help them.

Now, for the differences in logs content. Unfortunately, we're losing all the Engine logs, logs of systems that come from the engine. They just don't go through the Debug log handler, and therefore do not appear in our new Player.log file.

I passed two logs through a diff software to show exactly which lines are missing.

We have this header at the top of every log file

and we have some of the periodic Garbage Collection messages all over

Here's the warning and error tags again

Exceptions look slightly different for some reason, but not really meaningfully

There was also this message when I closed the game that was gone

So this is what this changelist does for now. I personally don't care much for those Engine logs, so I'm comfortable with this change, but maybe other people might have a different idea.

I was to emphasize that I think supporting the Portable Install feature is good. Without being able to put the log feature in the portable install, the feature is a failure, in my opinion. Through Googling, I could not find anyone researching solutions for portable installs of a Unity game, just the Unity Editor itself. But users do desire it, if only to have different settings for the many DFU versions they run (1.0, test builds, multiplayer, etc). It also helps people who are on a computer they don't own, from a temporary folder that they can easily backup and move around.

So yeah, drop your feedback in the meantime. I'll probably make another test build with all the unmerged DFU 1.1 PRs to get user feedback on a candidate build for 1.1.

PS: I do think we can also get point 1 benefits in other ways than creating a second log file. There's a big thread on this problem here: https://forum.unity.com/threads/debug-log-stacktrace-spam.489858/ (I find it kind of funny)
I think we might have to replace all the calls to Debug.Log in the project with Debug.LogFormat(...) with the "NoStackTrace" option. Or maybe that Stack Trace setting here

[numidium]

Mods that use the old Debug.Log will still send messages in the old format to the old log file after these changes, correct?

[KABoissonneault]

Mods that use the old Debug.Log will still send messages in the old format to the old log file after these changes, correct?

Notice that this change does not touch any of DFU's Debug.Log calls. The Debug.unityLogger.logHandler I assign in DaggerfallUnityApplication intercepts all calls to Debug.Log, even if I remove Unity's Player.log, and I create the same file in the same place (except we can move it once we have Portable Install).

None of the alternative solutions I suggest would affect mods. That's pretty essential. We can always intercept any of the Debug.Log or MonoBehaviour.log, the only ones we don't get are the Engine's logs

[John-Leitch]

Not an approved reviewer so just throwing this out, but should this itself be logged? Not sure how much exception swallowing matters here, but I think it's best avoided in most cases.

[KABoissonneault]

Done.

I managed to test this by putting Player-prev.log as read-only. The prev log is not replaced, and Player.log gets started anew normally.

[John-Leitch]

If you're planning on flushing after every write, you could set StreamWriter.AutoFlush to true. That would ensure consistent behavior in the future if somebody else updates the type.

[John-Leitch]

Since you're only writing, you might be able to simplify this with the File.Create convenience method.

[KABoissonneault]

Yeah one thing to close is simpler than two

[numidium]

This looks a lot nicer than our old logging. I just hope we're not losing anything useful for troubleshooting by excluding engine log messages.

[ajrb]

Haha, I really wish we'd fixed #1 years ago, the noise of the logs wound me up many times. Mostly I use the console in unity editor so it doesn't matter, but looking at player logs was painful at times.

I like the idea of just replacing the default with a more readable one. Does this affect the console in the editor at all? I assume not.

[KABoissonneault]

Does this affect the console in the editor at all? I assume not.

Good question, because it would be possible to affect the Editor console. If you look in DaggerfallUnityApplication.InitLog, I chose not to. It would have required keeping track of the default Unity log handler and only invoke it in Editor builds. I felt it was better to not replace the log handler in Editor.

[ajrb]

Definitely the right call.