microsoft / MixedRealityToolkit-Unity

This repository is for the legacy Mixed Reality Toolkit (MRTK) v2. For the latest version of the MRTK please visit https://github.com/MixedRealityToolkit/MixedRealityToolkit-Unity
https://aka.ms/mrtkdocs
MIT License
6k stars 2.12k forks source link

LogReceived event in SharingStage causes Unity Logs to be duplicated #1683

Closed pnolen closed 5 years ago

pnolen commented 6 years ago

Overview

In order to catch and display logs coming from the sharing service managed library, an event is registered in the SharingStage which catches incoming logs from the console and pipes them into the UnityEngine log system by way of the Log class in the SharingClient.dll (which in turn feeds the log into the ConsoleLogWriter class).

The problem is that the UnityEngine.Debug.Log, UnityEngine.Debug.LogWarning, UnityEngine.Debug.LogError and UnityEngine.Debug.LogException apparently also output into the console (most likely to put the logs into the Editor.log in AppData, but I'm speculating). This in turn triggers the Application.logMessageReceived event and prints the log to the Unity Console a second time.

This occurs for the above mentioned Debug log methods called from both the user's scripts as well as the Unity Engine itself.

Expected Behavior

Unity Debug logs should not be duplicated in the unity Console.

Actual Behavior

Unity Debug logs are outputted to the Console twice

First log example:

Vuforia initialization successful
UnityEngine.Debug:Log(Object)
Vuforia.VuforiaRuntime:InitVuforia()
Vuforia.VuforiaRuntime:VuforiaInitialization()

Duplicate log example:

Vuforia initialization successful
UnityEngine.Debug:Log(Object)
HoloToolkit.Sharing.Utilities.ConsoleLogWriter:WriteLogEntry(LogSeverity, String) (at Assets/TQ3D/HoloToolkit/Sharing/Scripts/Utilities/ConsoleLogWriter.cs:29)
HoloToolkit.Sharing.LogWriter:SwigDirectorWriteLogEntry(Int32, String) (at Assets/TQ3D/HoloToolkit/Sharing/Scripts/SDK/LogWriter.cs:65)
HoloToolkit.Sharing.SharingClientPINVOKE:Log_Info(String)
HoloToolkit.Sharing.Log:Info(String) (at Assets/TQ3D/HoloToolkit/Sharing/Scripts/SDK/Log.cs:44)
HoloToolkit.Sharing.SharingStage:OnLogReceived(String, String, LogType) (at Assets/TQ3D/HoloToolkit/Sharing/Scripts/SharingStage.cs:385)
UnityEngine.Debug:Log(Object)
Vuforia.VuforiaRuntime:InitVuforia()
Vuforia.VuforiaRuntime:VuforiaInitialization()

Note, however, that the duplicate log (the one piped through the ConsoleLogWriter) actually is outputted to the log first.

pnolen commented 6 years ago

The event for the log being received has three parameters: a string of the log, a string of the stack trace, and a LogType indicating the type of log (Info, Warning, Error, etc).

Due to the parameters to the event not being much more than the output, the only way I can think to fix this issue is to check the stack trace to see if the UnityEngine.Debug Log methods are already being referenced. The simplest fix would be to check to see if the string contains the text "UnityEngine.Debug:Log" which will catch calls to the Log, LogWarning, LogError, and LogException methods. The downside of this is that we're introducing a string contains check that will be called on every Log call, which is not the cheapest operation in the world.

An example of code that would fix this issue by using a string.Contains is as follows. If this seems acceptable I can fork and issue a pull request.

            // check to see if the log is coming from one of the UnityEngine.Log methods to prevent logs from appearing twice
            if ((type == LogType.Error || type == LogType.Assert || type == LogType.Exception || type == LogType.Warning || (ShowDetailedLogs && type == LogType.Log)) && stackTrace != null && stackTrace.Contains("UnityEngine.Debug:Log"))
                return;
wiwei commented 5 years ago

Closing issues older than 180 days. If this is still an issue, please reactivate with recent information.