Skip to content

MessageTemplateCache performance improvement #1946

@epeshk

Description

@epeshk

Currently, MessageTemplateCache uses HashTable (or Dictionary<T>/ConcurrentDictionary<T> in alternative implementations from Serilog.PerformanceTests.Support) with the string key to cache MessageTemplate objects.

These hash maps are initialized with default by-value comparer, and every cache lookup requires a linear scan of the string messageTemplate to compute the hash code (hash codes for strings aren't cached in current .NET implementations). This hash code computation is inefficient, especially for long message templates.

Since message template string objects are typically reused, and even constant for the cases like: _logger.Info("Log message, elapsed: {ElapsedTime}", ...), this cache may compare strings by-reference, instead of by-value, skipping the slow hash code computation.

I don't know if there any cases when by-value caching is useful, so I tested this proposal with two-level caching: by-reference, then by-value.

MessageTemplateCacheBenchmark_Cached benchmark for Hashtable-based MessageTemplateCache

Before optimization:

|    Method | Items | MaxDegreeOfParallelism |      Mean |    Error |   StdDev |   Gen0 | Allocated |
|---------- |------ |----------------------- |----------:|---------:|---------:|-------:|----------:|
| Hashtable |    10 |                     -1 |  29.34 us | 0.127 us | 0.119 us | 0.4578 |   7.77 KB |
| Hashtable |    10 |                      1 |  72.42 us | 0.379 us | 0.354 us |      - |   1.56 KB |
| Hashtable |    20 |                     -1 |  35.69 us | 0.069 us | 0.065 us | 0.4883 |   8.17 KB |
| Hashtable |    20 |                      1 | 145.06 us | 0.719 us | 0.638 us |      - |   1.56 KB |
| Hashtable |    50 |                     -1 |  43.35 us | 0.020 us | 0.018 us | 0.4883 |      8 KB |
| Hashtable |    50 |                      1 | 363.45 us | 0.809 us | 0.717 us |      - |   1.56 KB |
| Hashtable |   100 |                     -1 |  60.83 us | 0.188 us | 0.176 us | 0.4883 |    8.5 KB |
| Hashtable |   100 |                      1 | 734.14 us | 3.448 us | 2.879 us |      - |   1.56 KB |
| Hashtable |  1000 |                     -1 |  61.83 us | 0.256 us | 0.240 us | 0.4883 |   8.51 KB |
| Hashtable |  1000 |                      1 | 750.71 us | 2.810 us | 2.628 us |      - |   1.56 KB |

After optimization:

|    Method | Items | MaxDegreeOfParallelism |       Mean |     Error |    StdDev |   Gen0 | Allocated |
|---------- |------ |----------------------- |-----------:|----------:|----------:|-------:|----------:|
| Hashtable |    10 |                     -1 |  24.109 us | 0.0732 us | 0.0685 us | 0.4272 |   7.24 KB |
| Hashtable |    10 |                      1 |   9.950 us | 0.1350 us | 0.1263 us | 0.0916 |   1.56 KB |
| Hashtable |    20 |                     -1 |  32.101 us | 0.0682 us | 0.0638 us | 0.4883 |   8.38 KB |
| Hashtable |    20 |                      1 |  22.057 us | 0.0841 us | 0.0702 us | 0.0916 |   1.56 KB |
| Hashtable |    50 |                     -1 |  41.584 us | 0.2214 us | 0.2071 us | 0.4883 |      9 KB |
| Hashtable |    50 |                      1 |  52.199 us | 0.1128 us | 0.1000 us | 0.0610 |   1.56 KB |
| Hashtable |   100 |                     -1 |  47.072 us | 0.2052 us | 0.1919 us | 0.4883 |   8.53 KB |
| Hashtable |   100 |                      1 | 108.173 us | 0.4360 us | 0.4078 us |      - |   1.56 KB |
| Hashtable |  1000 |                     -1 |  46.534 us | 0.0949 us | 0.0841 us | 0.4883 |   8.52 KB |
| Hashtable |  1000 |                      1 | 120.535 us | 1.2397 us | 1.0990 us |      - |   1.56 KB |

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions