Cysharp / ZLogger

Zero Allocation Text/Structured Logger for .NET with StringInterpolation and Source Generator, built on top of a Microsoft.Extensions.Logging.
MIT License
1.25k stars 88 forks source link

Hello. In Unity 2018.4.7,ZLogger GC Alloc more than Unity Debug.Log ? #25

Closed justinlm closed 4 years ago

justinlm commented 4 years ago

Hello, I compare ZLogger with Unity Debug.Log in Unity Profile . And I get a result like this ZLogger

Here is my test code:

public class ZLogTest : MonoBehaviour
{
    static readonly ILogger<ZLogTest> zLogger = LogManager.GetLogger<ZLogTest>();
    void Start()
    {
        UnityEngine.Profiling.Profiler.BeginSample("zLogger");
        for (int i = 0; i < 10; i++)
        {
            zLogger.ZLogDebug("0000000000000000");
        }
        UnityEngine.Profiling.Profiler.EndSample();

        UnityEngine.Profiling.Profiler.BeginSample("Debug.Log");
        for (int i = 0; i < 10; i++)
        {
            Debug.Log("00000000000000000000011");
        }
        UnityEngine.Profiling.Profiler.EndSample();

        UnityEngine.Profiling.Profiler.BeginSample("zLogger format");
        for (int i = 0; i < 10; i++)
        {
            zLogger.ZLogDebug("foo{0} bar{1}", 10, 20);
        }
        UnityEngine.Profiling.Profiler.EndSample();

        UnityEngine.Profiling.Profiler.BeginSample("Debug.Log format");
        for (int i = 0; i < 10; i++)
        {
            Debug.LogFormat("foo{0} bar{1}", 10, 20);
        }
        UnityEngine.Profiling.Profiler.EndSample();
        int x = 10, y = 30, z = 40;

        UnityEngine.Profiling.Profiler.BeginSample("x+");
        var str1 = "x:" + x + " y:" + y + " z:" + z;
        UnityEngine.Profiling.Profiler.EndSample();

        UnityEngine.Profiling.Profiler.BeginSample("ZString.Concat");
        var str2 = ZString.Concat("x:", x, " y:", y, " z:", z);
        UnityEngine.Profiling.Profiler.EndSample();

        UnityEngine.Profiling.Profiler.BeginSample("string.Format");
        var str3 = string.Format("x:{0} y:{1} z:{2}", x, y, z);
        UnityEngine.Profiling.Profiler.EndSample();

        UnityEngine.Profiling.Profiler.BeginSample("ZString.Format");
        var str4 = ZString.Format("x:{0} y:{1} z:{2}", x, y, z);
        UnityEngine.Profiling.Profiler.EndSample();
    }
}

Are my results wrong? I am confused.

neuecc commented 4 years ago

ZLogger creates log entry cache. That cache will be reused when the log is flushed. Therefore, the allocate is occured when first run. Also, if you're using AddZLoggerUnityDebug, it's finnaly handled by UnityEngine.Debug.Log. It takes extra processing than the plain Debug.Log.

justinlm commented 4 years ago

Thank you for your answer. Yes, I am using AddZLoggerUnityDebug. em.... As you say, it takes extra processing than the plain Debug.Log. Is this means that I'd better not use ZLogger to log to unity's console?

neuecc commented 4 years ago

If you don't use any of ZLogger's additional features, then yes. For example, filtering at the log level for development and production, categorization, etc...

justinlm commented 4 years ago

Thank you so much for your reply and advice。