Debug.Log Stacktrace Spam

Oh, and another absolutely minor request: Can you modify StackTraceUtility.ExtractStackTrace() to accept an optional skipFrames argument? E.g.:

Code (CSharp):

1.  
2.     [SecuritySafeCritical]
3.     [RequiredByNativeCode]
4.     public static string ExtractStackTrace(int skipFrames = 1)
5.     {
6.         StackTrace stackTrace = new StackTrace(skipFrames, fNeedFileInfo: true);
7.         return ExtractFormattedStackTrace(stackTrace).ToString();
8.     }

 

And last but not least, here's an example of how you can override the default Debug.Log (if you wanted to add your own filtering or decoration logic) and get the stack trace you want. As stated above, you can click on the script references in the Console to go to the appropriate line of code (at least as I've tested in 2019). However, you can't double click on the message itself to go to the first line of code. Almost there!

To use: just call Debug.Log() as you normally would. Instead of using UnityEngine.Debug.Log, it will use this version instead.

Code (CSharp):

1. using System;
2. using System.Diagnostics;
3. using System.Globalization;
4. using System.Reflection;
5. using UnityEngine;
6.  
7. namespace [YourNamespace]
8. {
9.     public class Debug : UnityEngine.Debug
10.     {
11.         private static (ILogHandler logHandler, MethodInfo method) internalLog = default;
12.  
13.         static Debug()
14.         {
15.             Type stackTraceType = typeof(StackTraceUtility);
16.             var extractFormattedStackTrace = stackTraceType.GetMethod("ExtractFormattedStackTrace", System.Reflection.BindingFlags.Static | System.Reflection.BindingFlags.Public | System.Reflection.BindingFlags.NonPublic);
17.             ExtractFormattedStackTrace = (skipFrames) =>
18.             {
19.                 StackTrace stackTrace = new StackTrace(skipFrames, fNeedFileInfo: true);
20.                 return extractFormattedStackTrace.Invoke(null, new object[] { stackTrace }) as string;
21.             };
22.         }
23.  
24.         private delegate string GenericReturnDelegate(int skipFrames);
25.         private static readonly GenericReturnDelegate ExtractFormattedStackTrace = null;
26.  
27.         private static ILogger Logger
28.         {
29.             get { return UnityEngine.Debug.unityLogger; }
30.         }
31.  
32.         private static ILogHandler LogHandler
33.         {
34.             get { return Logger.logHandler; }
35.         }
36.  
37.         public static new void Log(object message, UnityEngine.Object context = null)
38.         {
39.             if (Logger.IsLogTypeAllowed(LogType.Log))
40.             {
41.                 string formattedMessagePlusStackTrace = GetString(message);
42.                 formattedMessagePlusStackTrace += "\n" + ExtractFormattedStackTrace(2);
43.                 CallInternalLogForCurrentLogger(LogType.Log, formattedMessagePlusStackTrace, context);
44.             }
45.         }
46.  
47.         private static void CallInternalLogForCurrentLogger(LogType logType, string message, UnityEngine.Object context)
48.         {
49.             if (internalLog.logHandler != LogHandler)
50.             {
51.                 Type type = LogHandler.GetType();
52.                 var method = type.GetMethod("Internal_Log", System.Reflection.BindingFlags.Static | System.Reflection.BindingFlags.Public | System.Reflection.BindingFlags.NonPublic);
53.                 internalLog = (LogHandler, method);
54.             }
55.  
56.             internalLog.method.Invoke(null, new object[] { LogType.Log, LogOption.NoStacktrace, message, context });
57.         }
58.  
59.         //Pulled from UnityEngine.CoreModule
60.         private static string GetString(object message)
61.         {
62.             if (message == null)
63.             {
64.                 return "Null";
65.             }
66.             IFormattable formattable = message as IFormattable;
67.             if (formattable != null)
68.             {
69.                 return formattable.ToString(null, CultureInfo.InvariantCulture);
70.             }
71.             return message.ToString();
72.         }
73.     }
74. }
75.  

 

The problem with Unity's logs is that they build a stack trace which uses Reflection and Reflection is very slow. Therefore we will use Debug.LogFormat and pass the LogOption.NoStacktrace to prevent this.

So, now we all say thank you to Roslyn.
If your using Roslyn you can write debug wrapper like this.

Code (CSharp):

1.  
2.     public static class Logger
3.     {
4.         // usage : Logger.Log("Something Happened");
5.         //            : Logger.Log($" Log some variable { i }");
6.         //
7.         public static void Log(string msg, [CallerMemberName] string methodName = null, [CallerFilePath] string fileName = null, [CallerLineNumber] int lineNo = -1)
8.         {
9.             msg= $"{fileName},{methodName},{lineNo},{msg??"NULL"}");
10.             UnityEngine.Debug.LogFormat( LogType.Log, LogOption.NoStacktrace, null, "{0}", msg ?? "NULL" );
11.         }
12.     }

Sadly, in 2020.1 LogFormat requires a format string.
The Attributes parameters passed to methodName, fileName and lineNo are created by the compiler (Rosyln) and passed as literals. .You call the method with only a single string. Because this is done at compile time there is zero reflection, no slow down and yet you still get some call information.
The only down side is that your executables could get a bit larger.

 

You can configure that in Player Settings > Other Settings:

 

As discussed many times before, we want debug data - we do not want redundant stacks to the log itself that seem to be completely separate from any other stacktrace (on its own paragraph; not part of the stacktrace).

 

My answer is to the quoted text in my post, nothing else. The context is important and in this context, I'm pretty sure the answer is correct.

 

Yes, you are correct that you can disable the stack trace in the editor.
I wanted to show that you can control the stack trace behavior in code as well.
I also wanted to show that you can get caller information for free via attributes without using the expensive stack tracing
Realistically 99 percent of the time you just want to know what line caused the error not how you got there.
With some minor change you could get both.
I really wish I could offer a clickable link to the code from the attributes also.

 

@Rarepops You still around bud? You mentioned this in January -- Soo... :ahem: .... how's it going?

 

@Rarepops The issue was that Unity spams the line (Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35) below each Debug.Log() entry, which is still happening in Unity 2020.1.13f1.

 

Still happening in 2019.4.18f1. Here is the first instance in my adb logcat output (which is Unity's code):

01-18 22:28:51.225 15197 15220 I Unity : XRGeneral Settings awakening...
01-18 22:28:51.225 15197 15220 I Unity : UnityEngine.DebugLogHandler:Internal_Log(LogType, LogOption, String, Object)
01-18 22:28:51.225 15197 15220 I Unity : UnityEngine.DebugLogHandler:LogFormat(LogType, Object, String, Object[])
01-18 22:28:51.225 15197 15220 I Unity : UnityEngine.Logger:Log(LogType, Object)
01-18 22:28:51.225 15197 15220 I Unity : UnityEngine.Debug:Log(Object)
01-18 22:28:51.225 15197 15220 I Unity : UnityEngine.XR.Management.XRGeneralSettings:Awake()
01-18 22:28:51.225 15197 15220 I Unity :
01-18 22:28:51.225 15197 15220 I Unity : (Filename: ./Runtime/Export/Debug/Debug.bindings.h Line: 35)

Another example from my own Debug.Log() call:

01-18 22:28:56.351 15197 15220 I Unity : Startup called.
01-18 22:28:56.351 15197 15220 I Unity : UnityEngine.DebugLogHandler:Internal_Log(LogType, LogOption, String, Object)
01-18 22:28:56.351 15197 15220 I Unity : UnityEngine.DebugLogHandler:LogFormat(LogType, Object, String, Object[])
01-18 22:28:56.351 15197 15220 I Unity : UnityEngine.Logger:LogFormat(LogType, String, Object[])
01-18 22:28:56.351 15197 15220 I Unity : UnityEngine.Debug:LogFormat(String, Object[])
01-18 22:28:56.351 15197 15220 I Unity : <Start>d__22:MoveNext()
01-18 22:28:56.351 15197 15220 I Unity : UnityEngine.SetupCoroutine:InvokeMoveNext(IEnumerator, IntPtr)
01-18 22:28:56.351 15197 15220 I Unity :
01-18 22:28:56.351 15197 15220 I Unity : (Filename: ./Runtime/Export/Debug/Debug.bindings.h Line: 35)

 

Done!

 

Running under Unity v2020.1.2.8073916

I've read this whole thread.
(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

And I was like huh, this is strange.
(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

Why does the log file still look like this?
(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

(Filename: C:\buildslave\unity\build\Runtime/Export/Debug/Debug.bindings.h Line: 35)

PS
I am not a Unity developer. I'm a user who is trying to debug a mod made for a game made in Unity.

 

You forgot to read the post above yours:

 

The point of my post was that you can get some stack data without paying the Reflection price.
Disabling this removes all information and leaves you blind.

 

Bump, still a problem.

I want my log message, not the rest. It's also a big pain on device logs too, e.g. Android logcat.

9024: [2022-06-16T13:59:58Z - Unity] My log message that I'm in interested in.
9025: [2022-06-16T13:59:58Z - Unity] UnityEngine.StackTraceUtility:ExtractStackTrace ()
9026: [2022-06-16T13:59:58Z - Unity] UnityEngine.DebugLogHandler:LogFormat (UnityEngine.LogType,UnityEngine.Object,string,object[])
9027: [2022-06-16T13:59:58Z - Unity] UnityEngine.Logger:Log (UnityEngine.LogType,object)
9028: [2022-06-16T13:59:58Z - Unity] UnityEngine.Debug:Log (object)
...

@Unity think of the disk space you'll save on your cloud builds!
(As well as all the developers you'll cease to annoy, but that doesn't appear to be a motivator)

 

I think what we all want is the ability to just exclude certain methods from the actual trace.
When I'm debugging, I certainly don't need to see StackTraceUtility:ExtractStackTrace or UnityEngine.Debug:Log on every message.
The "extra" noise is MOST of the logs, which makes it harder to actually parse them when you're reading.
I resorted to post-process my logs for reading, but it would be much nicer to have it done in the engine itself.

 

7+ years later and this thread is still the most relevant. Sigh... Slightly less bloaty
UnityEngine.Debug:Log (object)

Should I be surprised?
UnityEngine.Debug:Log (object)

Come on, Unity
UnityEngine.Debug:Log (object)

Imagine if our forums had this spam, too
UnityEngine.Debug:Log (object)

It's quite hard to read when you're looking at thousands per day
UnityEngine.Debug:Log (object)

---
Imagine if this post, instead, looked like:

7+ years later and this thread is still the most relevant. Sigh... Slightly less bloaty
Should I be surprised?
Come on, Unity
Imagine if our forums had this spam, too
It's quite hard to read when you're looking at thousands per day