1

Following How to decorate code in C# wiithout C/C++ - like macros I have just switched my logging system over to accept log messages as lambdas rather than as strings:

void Log(Func<string> msg)
{
    if (logIsEnabled)
    {
        Debug.Write(msg());
    }
}

My understanding is that this is much better, performance-wise, in that if I write:

Log(() => "foo(" + myInteger + ")");

then the string foo(42) is constructed only if logIsEnabled. For the sake of this question, let's assume that Log() is being called at high frequency, and constructing these strings for the log comes at an undesirable cost.

Suddenly I worried, though - is a lambda being instantiated every time this line of code is reached? Might that be more of a performance cost than constructing a string? I'm not clear on what's happening here, under the hood.

So, my question is: how is the lambda actually implemented? Is it constructed at compile-time and passed just as a pointer to a function? Is it constructed on first use and on subsequent passes just a pointer? Or is it constructed every time the line of code executes?

Theodor Zoulias
  • 34,835
  • 7
  • 69
  • 104
DoyDoy
  • 35
  • 4
  • 3
    "That would be bad, I guess, probably worse" - rather than relying on guesswork, if performance is important to you, set specific goals, then try both alternatives you're considering and *measure*. There's little point in inventing hypothetical problems rather than solving your real ones. – Damien_The_Unbeliever Sep 14 '22 at 14:33
  • The language specification poses no constraint on how the compiler implements this. Practically speaking, the compiler will construct the delegate from an anonymous method but once, and cache the results, but it isn't *obligated* to do so. Incidentally, it is not necessarily the case that it's "much better" for performance to check `logEnabled`, because this depends both on how `logEnabled` is declared (a `static readonly` is much different from an instance field) and how expensive your expressions really are (`"f" + "o" + "o"` is a zero-allocation *constant*). All good reasons to benchmark! – Jeroen Mostert Sep 14 '22 at 14:44
  • Just use a logging framework. Something like nLog have such methods already. But you would typically not use it unless you had some special reason to. Formatting a string is fairly cheap, and you should typically not log so often that it becomes a performance issue. – JonasH Sep 14 '22 at 14:50
  • Linked as duplicate: [What are C# lambda's compiled into? A stackframe, an instance of an anonymous type, or?](https://stackoverflow.com/questions/8993426/what-are-c-sharp-lambdas-compiled-into-a-stackframe-an-instance-of-an-anonymo) But as far as I can see it's not the same question, nor it contains the answer to this question. – Theodor Zoulias Sep 14 '22 at 15:13
  • Looking at [this](https://stackoverflow.com/a/37350865/8170844) answer, it looks like if you implement your logging using `FormattableString` you could use string interpolation which will only get called if you call `ToString()` – Yitz Sep 14 '22 at 15:48
  • 1
    @Damien_The_Unbeliever Whilst measurement is the most direct arbiter of performance, I also want to understand the issue in order to inform this, and future, designs. Understanding what's happening under the hood seems to me to be at least as important, in this case, as empirical performance. I'm sorry, I think I wasn't clear on that in the question. – DoyDoy Sep 14 '22 at 16:26
  • @JeroenMostert `"f" + "o" + "o"` was supposed to be a simple example - perhaps it was too simple to be useful, sorry. I intended to make an example of 'some expensive string building' (expensive in object creation as well as CPU time, perhaps). – DoyDoy Sep 14 '22 at 16:27
  • @JonasH Thanks, I'll make a note to look into nLog - I expect that's the right thing to do. I'm still interested in the answer, however. On the frequency of logging, thing: I would like to be able to Log() freely, even once per iteration, without worrying too much about performance drain, for developer convenience. Logging less often is another, but less convenient (in my case), approach to the problem. – DoyDoy Sep 14 '22 at 16:34
  • I think you probably just want sting interpolation which should have good performace – Hogan Sep 15 '22 at 01:09
  • The advice you are following is no longer relevant. The modern replacement is interpolated string handlers. – Jeremy Lakeman Sep 15 '22 at 05:01

1 Answers1

1

is a lambda being instantiated every time this line of code is reached?

Yes. Not only a new Func<string> is instantiated every time, but also a small compiler-generated class. Let's post some code to SharpLab, and see what comes out:

using System;

class Program
{
    static bool logIsEnabled;

    static void Main()
    {
        logIsEnabled = true;
        int myInteger = 13;
        Log(() => "foo(" + myInteger + ")");
    }

    static void Log(Func<string> msg)
    {
        if (logIsEnabled)
        {
            Console.WriteLine(msg());
        }
    }
}

SharpLab output (sanitized):

using System;
using System.Runtime.CompilerServices;

internal class Program
{
    [CompilerGenerated]
    private sealed class DisplayClass
    {
        public int myInteger;

        internal string M()
        {
            return string.Concat("foo(", myInteger.ToString(), ")");
        }
    }

    private static bool logIsEnabled;

    private static void Main()
    {
        DisplayClass displayClass = new DisplayClass();
        logIsEnabled = true;
        displayClass.myInteger = 13;
        Log(new Func<string>(displayClass.M));
    }

    private static void Log(Func<string> msg)
    {
        if (logIsEnabled)
        {
            Console.WriteLine(msg());
        }
    }
}

The DisplayClass is the closure that the compiler had to generate, in order to hold the myInteger variable. This variable is hoisted to a public field of the DisplayClass class.

The Visual Studio can help you at detecting that a variable has been captured. Just hover the mouse over the lambda operator (=>).

Visual Studio screenshot

It is possible to avoid the allocation of the two objects by passing the myInteger as an argument, instead of relying on the convenience of captured variables and closures. Here is how:

using System;

class Program
{
    static bool logIsEnabled;

    static void Main()
    {
        logIsEnabled = true;
        int myInteger = 13;
        Log(arg => "foo(" + arg + ")", myInteger);
    }

    static void Log<TArg>(Func<TArg, string> msg, TArg arg)
    {
        if (logIsEnabled)
        {
            Console.WriteLine(msg(arg));
        }
    }
}

SharpLab output (sanitized):

using System;
using System.Runtime.CompilerServices;

internal class Program
{
    [Serializable]
    [CompilerGenerated]
    private sealed class C
    {
        public static readonly C singleton = new C();

        public static Func<int, string> lambda;

        internal string M(int arg)
        {
            return string.Concat("foo(", arg.ToString(), ")");
        }
    }

    private static bool logIsEnabled;

    private static void Main()
    {
        logIsEnabled = true;
        int arg = 13;
        Log(C.lambda ?? (C.lambda = new Func<int, string>(C.singleton.M)), arg);
    }

    private static void Log<TArg>(Func<TArg, string> msg, TArg arg)
    {
        if (logIsEnabled)
        {
            Console.WriteLine(msg(arg));
        }
    }
}

Now the compiler generated a singleton (the C class), and the Func<TArg, string> is instantiated only once per TArg type. So if your program uses the Log<TArg> with ints, strings and decimals, only a Func<int, string>, a Func<string, string> and a Func<decimal, string> will be created in total, irrespective of how many times the Log<TArg> will be invoked.

In case you want to pass more than one arguments to the Log method, you'll have to write additional Log<TArg1, TArg2>, Log<TArg1, TArg2, TArg3> etc overloads.

Theodor Zoulias
  • 34,835
  • 7
  • 69
  • 104