Experiment with C# 11 preview of abstract static interface methods and CallerArgumentExpression as cache key

[johnjuuljensen]

Hey.

I've implemented something very similar at work and had a few ideas I wanted to try out. Since our solutions are so similar but you have a nice benchmark setup it seemed sensible to try my ideas here and share the results.

The experiments are:

• Using C# 11 preview of abstract static interface methods to eliminate the need for multiple InterpolatedStringHandlers.

• Using CallerArgumentExpression in extensions methods (handlerExpr) to get the original interpolated string expression and using it as cache key. The value of handlerExpr takes the form: $"ABCD{arg1}EFGH{arg2}IJKL{arg3}MNOP{arg4}QRST{arg5}UVWX" It doesn't seem possible to pass handlerExpr as an argument to the interpolation handler, which is a shame, since it would have allowed skipping recording anything other than the arguments.

I don't use ArrayPool in my own implementation since I'm a little scared of leaks. I only added it here for fun to get better results in the benchmark. The experiment is a little rough and I'm not sure it's and apples to apples comparison but the results are good:

|                                          Method | IsEnabled | EnableCaching |         Mean | Ratio |   Gen0 | Allocated | Alloc Ratio |
|------------------------------------------------ |---------- |-------------- |-------------:|------:|-------:|----------:|------------:|
|                                        Standard |     False |         False |    14.748 ns |  1.00 |      - |         - |          NA |
|             InterpolatedWithManualDestructuring |     False |         False |     4.267 ns |  0.30 |      - |         - |          NA |
|  InterpolatedWithExplicitAutomaticDestructuring |     False |         False |     4.035 ns |  0.28 |      - |         - |          NA |
|  InterpolatedWithImplicitAutomaticDestructuring |     False |         False |     4.410 ns |  0.31 |      - |         - |          NA |
|            Interpolated2WithManualDestructuring |     False |         False |     4.811 ns |  0.33 |      - |         - |          NA |
| Interpolated2WithExplicitAutomaticDestructuring |     False |         False |     4.226 ns |  0.29 |      - |         - |          NA |
| Interpolated2WithImplicitAutomaticDestructuring |     False |         False |     4.594 ns |  0.32 |      - |         - |          NA |
|                                                 |           |               |              |       |        |           |             |
|                                        Standard |     False |          True |    14.830 ns |  1.00 |      - |         - |          NA |
|             InterpolatedWithManualDestructuring |     False |          True |     4.361 ns |  0.30 |      - |         - |          NA |
|  InterpolatedWithExplicitAutomaticDestructuring |     False |          True |     6.292 ns |  0.43 |      - |         - |          NA |
|  InterpolatedWithImplicitAutomaticDestructuring |     False |          True |     5.452 ns |  0.37 |      - |         - |          NA |
|            Interpolated2WithManualDestructuring |     False |          True |     5.251 ns |  0.35 |      - |         - |          NA |
| Interpolated2WithExplicitAutomaticDestructuring |     False |          True |     4.116 ns |  0.28 |      - |         - |          NA |
| Interpolated2WithImplicitAutomaticDestructuring |     False |          True |     4.173 ns |  0.27 |      - |         - |          NA |
|                                                 |           |               |              |       |        |           |             |
|                                        Standard |      True |         False | 2,889.727 ns |  1.00 | 0.7706 |    1616 B |        1.00 |
|             InterpolatedWithManualDestructuring |      True |         False | 3,973.308 ns |  1.37 | 1.3351 |    2792 B |        1.73 |
|  InterpolatedWithExplicitAutomaticDestructuring |      True |         False | 4,064.250 ns |  1.40 | 1.3351 |    2792 B |        1.73 |
|  InterpolatedWithImplicitAutomaticDestructuring |      True |         False | 4,104.125 ns |  1.43 | 1.3199 |    2760 B |        1.71 |
|            Interpolated2WithManualDestructuring |      True |         False | 2,996.425 ns |  1.04 | 0.7591 |    1592 B |        0.99 |
| Interpolated2WithExplicitAutomaticDestructuring |      True |         False | 3,039.021 ns |  1.05 | 0.7591 |    1592 B |        0.99 |
| Interpolated2WithImplicitAutomaticDestructuring |      True |         False | 2,979.040 ns |  1.03 | 0.7591 |    1592 B |        0.99 |
|                                                 |           |               |              |       |        |           |             |
|                                        Standard |      True |          True | 2,862.356 ns |  1.00 | 0.7706 |    1616 B |        1.00 |
|             InterpolatedWithManualDestructuring |      True |          True | 3,438.223 ns |  1.20 | 0.8698 |    1824 B |        1.13 |
|  InterpolatedWithExplicitAutomaticDestructuring |      True |          True | 3,287.397 ns |  1.15 | 0.8698 |    1824 B |        1.13 |
|  InterpolatedWithImplicitAutomaticDestructuring |      True |          True | 3,350.591 ns |  1.19 | 0.8850 |    1856 B |        1.15 |
|            Interpolated2WithManualDestructuring |      True |          True | 3,013.102 ns |  1.06 | 0.7591 |    1592 B |        0.99 |
| Interpolated2WithExplicitAutomaticDestructuring |      True |          True | 3,006.917 ns |  1.06 | 0.7591 |    1592 B |        0.99 |
| Interpolated2WithImplicitAutomaticDestructuring |      True |          True | 3,022.641 ns |  1.06 | 0.7591 |    1592 B |        0.99 |

Hopefully they'll expand the capabilities of interpolated string handlers in C#11. My personal wishlist includes:

• Being able to pass constants to the constructor
• Getting the original string expression
• Guarantees on how many calls to AppendLiteral you can expect
• Maybe an AppendDone method
• The ability to somehow get a stack allocated Span<Char> for alloc free string composistion. There are probably more complications to this than I've thought of though.

Anyways that's it. Thanks for building this project :)

[fedarovich]

Hey.

Thank you for being interested in this project!

Using abstract static interface methods looks promising, so I will consider using this approach when C# 11 is released.

I have also considered using CallerArgumentExpression in extensions methods to get the original interpolated string expression and using it as cache key. But while it provides a good performance, unfortunately it is not compatible with the value representation policies other than the default one. If a value representation policy returns Destructure or Stringify for some argument, ISLE has to build the message template from scratch. Even worse, if two places in code use the same interpolated string with arguments of different types, the resulting message templates may be different. That's why the current cache implementation is done in a form of a tree. By the way, there will be some optimizations of it in version 1.4.

I agree that it would be great to have interpolated string handler enhancements you've mentioned. It would also be nice to have duck-typed Dispose method, to prevent memory leaks in case some pool (e.g. ArrayPool) is used and exception is thrown while executing the handler.

[johnjuuljensen]

But while it provides a good performance, unfortunately it is not compatible with the value representation policies other than the default one

I'm no expert on Serilog (at all), but I browsed the code while looking for the most optimal way to call it, and in Serilog the call flow looks like: Logger.Write (or Logger.BindMessageTemplate) -> MessageTemplateProcessor.Process -> MessageTemplateCache.Parse

MessageTemplateCache.Parse does a lookup on the raw template string passed to the top-level Write in a hashtable and returns a MessageTemplate. And in the subsequent call to ConstructProperties it only references the template to determine the number of expected parameters.

So it looks like Serilog itself does the same caching, and I decided to build on top of that by simply building a new Seri-friendly template string in my interpolated string handler and just pass that to Serilog. And that's where the CallerArgumentExpression comes into play, I use it in a simple <string,string> dictionary to map the CallerArgumentExpression to the Seri-friendly string.

For now I just add @ to all arguments in the template I build and it works well, but it's not in heavy use yet, so I might run into some of the problems you mention.