Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Optimize InlineFormatter #557

Merged
merged 3 commits into from
May 8, 2021
Merged

Optimize InlineFormatter #557

merged 3 commits into from
May 8, 2021

Conversation

benbryant0
Copy link
Contributor

@benbryant0 benbryant0 commented Apr 25, 2021

This PR updates BenchmarkDotNet, adds a benchmark for InlineFormatter.FormatSql, and optimizes that method.

When trying to pin down performance issues with MiniProfiler it was reporting a step as taking >60 seconds when that step just wrapped an SQL command that it reported as taking ~1.5 seconds. The SQL was run through Dapper and had a huge IN () statement using a list parameter with ~14k items. After some investigation I found out that it only happened when there was an active MiniProfiler session and that it wouldn't happen if I put the values directly in the query instead of passing them as a parameter. Eventually I ended up at InlineFormatter.FormatSql.

When benchmarking it I found that performance was dramatically worse when a parameter object's name property lacks a DB param prefix: @:?. This triggers this line which scans the command text with regex to determine the correct prefix. This is relatively expensive and scales badly. Unfortunately, this seems to be the usual case for EF 6 parameters and Dapper list expansions (the latter being my case).

I played around with a lot of different ways to improve this and I think what I have now is somewhat balanced between readability and performance. The average time with/without the prefixing is almost equivalent now, with allocation down 23x for the worst 10 param case. That increases as more params are used, so my 14k param case went from ~35s & 6.8 GB allocated to ~2.4s and 8.2 MB.

Before:

|       Runtime | NumParams | ParamNamePrefixed |           Mean |         Error |        StdDev |     Gen 0 |     Gen 1 |    Gen 2 |   Allocated |
|-------------- |---------- |------------------ |---------------:|--------------:|--------------:|----------:|----------:|---------:|------------:|
|      .NET 4.8 |        10 |             False |     100.450 us |     1.8618 us |     1.6504 us |   23.8037 |    2.3193 |        - |   146.66 KB |
| .NET Core 3.1 |        10 |             False |     112.923 us |     2.2559 us |     5.4483 us |   17.4561 |    8.5449 |   0.1221 |   107.09 KB |
|      .NET 4.8 |        10 |              True |      15.172 us |     0.2989 us |     0.4091 us |    2.9907 |    0.0458 |        - |    18.41 KB |
| .NET Core 3.1 |        10 |              True |       9.520 us |     0.1389 us |     0.1299 us |    1.6479 |    0.0153 |        - |    10.19 KB |
|      .NET 4.8 |       100 |             False |   2,292.919 us |    11.8154 us |    10.4740 us |  273.4375 |   31.2500 |        - |  1695.21 KB |
| .NET Core 3.1 |       100 |             False |   2,386.038 us |    47.6987 us |    63.6764 us |  191.4063 |   89.8438 |   3.9063 |  1177.15 KB |
|      .NET 4.8 |       100 |              True |     630.021 us |    12.4270 us |    11.6242 us |  181.6406 |   29.2969 |        - |  1121.71 KB |
| .NET Core 3.1 |       100 |              True |     690.346 us |     9.3215 us |     8.7194 us |  124.0234 |   60.5469 |   0.9766 |    760.8 KB |
|      .NET 4.8 |      1000 |             False | 159,135.878 us | 2,073.0085 us | 1,939.0934 us | 7000.0000 |  250.0000 |        - | 43936.55 KB |
| .NET Core 3.1 |      1000 |             False | 153,967.456 us |   682.2992 us |   569.7507 us | 4000.0000 | 1750.0000 | 250.0000 | 24116.82 KB |
|      .NET 4.8 |      1000 |              True |  17,040.505 us |   332.3331 us |   408.1349 us | 6187.5000 | 2187.5000 |        - | 38190.68 KB |
| .NET Core 3.1 |      1000 |              True |  17,211.037 us |   278.4245 us |   260.4384 us | 3250.0000 | 1281.2500 |  31.2500 | 19923.27 KB |

After:

|       Runtime | NumParams | ParamNamePrefixed |          Mean |       Error |      StdDev |   Gen 0 |   Gen 1 | Gen 2 | Allocated |
|-------------- |---------- |------------------ |--------------:|------------:|------------:|--------:|--------:|------:|----------:|
|      .NET 4.8 |        10 |             False |      9.369 us |   0.1105 us |   0.0979 us |  1.0223 |       - |     - |   6.35 KB |
| .NET Core 3.1 |        10 |             False |      6.700 us |   0.0923 us |   0.0819 us |  0.7629 |       - |     - |   4.72 KB |
|      .NET 4.8 |        10 |              True |      9.465 us |   0.1805 us |   0.1931 us |  1.0834 |       - |     - |   6.75 KB |
| .NET Core 3.1 |        10 |              True |      7.039 us |   0.0747 us |   0.0662 us |  0.8316 |       - |     - |   5.11 KB |
|      .NET 4.8 |       100 |             False |    200.240 us |   2.0864 us |   1.9516 us |  9.0332 |  0.2441 |     - |   56.9 KB |
| .NET Core 3.1 |       100 |             False |    172.233 us |   1.6221 us |   1.4379 us |  7.0801 |       - |     - |  44.12 KB |
|      .NET 4.8 |       100 |              True |    200.665 us |   3.4022 us |   3.0160 us |  9.7656 |  0.2441 |     - |  60.82 KB |
| .NET Core 3.1 |       100 |              True |    183.333 us |   1.9839 us |   1.7586 us |  7.8125 |  0.2441 |     - |  48.03 KB |
|      .NET 4.8 |      1000 |             False | 12,971.975 us | 121.8732 us | 108.0374 us | 93.7500 | 15.6250 |     - | 592.42 KB |
| .NET Core 3.1 |      1000 |             False | 12,511.909 us |  92.2871 us |  77.0639 us | 62.5000 |       - |     - | 449.57 KB |
|      .NET 4.8 |      1000 |              True | 12,979.041 us | 249.3787 us | 266.8324 us | 93.7500 | 15.6250 |     - | 638.51 KB |
| .NET Core 3.1 |      1000 |              True | 12,550.432 us | 125.3347 us | 104.6601 us | 78.1250 | 15.6250 |     - | 488.61 KB |

Requires explicitly specifying the LangVersion as BDN doesn't like 'latest' when compiling the project to bench it
return Regex.Replace(
commandText,
regexPattern,
m => paramValuesByName[m.Value.Substring(1).ToLower()],
Copy link
Contributor Author

@benbryant0 benbryant0 Apr 25, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Capture groups are relatively expensive for .NET regex, and benchmarking showed that doing it this way would drop allocations by ~20%.

Copy link
Member

@NickCraver NickCraver left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is excellent work and detail - thank you so much for improving this case tremendously <3

@NickCraver NickCraver merged commit c521319 into MiniProfiler:main May 8, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants