To Sp or Not To Sp—Part 2

In the first article in this two-part series, we analyzed the difference between copying using EF and copying using a stored procedure. Now, let’s see how much faster the stored procedure is and compare the performance of both approaches: ORM vs SP. how much Background If you haven’t read the first part of the article yet, I strongly recommend reading it here: To Sp or Not To Sp. To Sp or Not To Sp You can find all the code from this article in the GitHub repository here: pavelgelver.com-articles/sp-or-not-sp-pt2. You can find all the code from this article in the GitHub repository here: pavelgelver.com-articles/sp-or-not-sp-pt2. pavelgelver.com-articles/sp-or-not-sp-pt2 Here’s a quick refresher of what we covered in the first article. The code is as follows (rewritten slightly to make it more compact): public class EntityFrameworkReplicator : IReplicator { private readonly AppDbContext _dbContext; public EntityFrameworkReplicator(AppDbContext dbContext) => _dbContext = dbContext; public async Task CopyStructureAsync(int sourceId, int targetId) { await using var transaction = await _dbContext.Database.BeginTransactionAsync(); try { await CopyAsync (sourceId, targetId); await CopyAsync (sourceId, targetId); await CopyAsync (sourceId, targetId); await transaction.CommitAsync(); } catch { // handle } } private async Task CopyAsync (int sourceId, int targetId) where T : StructureEntity, new() { IAsyncEnumerable sourceObjects = _dbContext.Set () .Where(node => node.StructureId == sourceId) .AsAsyncEnumerable(); await foreach(var obj in sourceObjects) { var newNode = CreateCopy(obj, targetId); _dbContext.Set ().Add(newNode); } await _dbContext.SaveChangesAsync(); } private static T CreateCopy (T source, int targetId) where T : StructureEntity, new() { return new T { StructureId = targetId, SomeId1 = source.SomeId1, SomeId2 = source.SomeId2, SomeBool1 = source.SomeBool1, SomeString = source.SomeString, Created1 = source.Created1 }; } } public class EntityFrameworkReplicator : IReplicator { private readonly AppDbContext _dbContext; public EntityFrameworkReplicator(AppDbContext dbContext) => _dbContext = dbContext; public async Task CopyStructureAsync(int sourceId, int targetId) { await using var transaction = await _dbContext.Database.BeginTransactionAsync(); try { await CopyAsync (sourceId, targetId); await CopyAsync (sourceId, targetId); await CopyAsync (sourceId, targetId); await transaction.CommitAsync(); } catch { // handle } } private async Task CopyAsync (int sourceId, int targetId) where T : StructureEntity, new() { IAsyncEnumerable sourceObjects = _dbContext.Set () .Where(node => node.StructureId == sourceId) .AsAsyncEnumerable(); await foreach(var obj in sourceObjects) { var newNode = CreateCopy(obj, targetId); _dbContext.Set ().Add(newNode); } await _dbContext.SaveChangesAsync(); } private static T CreateCopy (T source, int targetId) where T : StructureEntity, new() { return new T { StructureId = targetId, SomeId1 = source.SomeId1, SomeId2 = source.SomeId2, SomeBool1 = source.SomeBool1, SomeString = source.SomeString, Created1 = source.Created1 }; } } As an alternative, I wrote a simple SQL stored procedure: CREATE PROCEDURE CopyStructure @SourceStructureId INT, @TargetStructureId INT AS BEGIN BEGIN TRAN INSERT INTO Nodes (StructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1) SELECT @TargetStructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1 FROM Nodes WHERE StructureId = @SourceStructureId INSERT INTO Permissions (StructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1) SELECT @TargetStructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1 FROM Permissions WHERE StructureId = @SourceStructureId INSERT INTO Attributes (StructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1) SELECT @TargetStructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1 FROM Attributes WHERE StructureId = @SourceStructureId COMMIT END; CREATE PROCEDURE CopyStructure @SourceStructureId INT, @TargetStructureId INT AS BEGIN BEGIN TRAN INSERT INTO Nodes (StructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1) SELECT @TargetStructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1 FROM Nodes WHERE StructureId = @SourceStructureId INSERT INTO Permissions (StructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1) SELECT @TargetStructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1 FROM Permissions WHERE StructureId = @SourceStructureId INSERT INTO Attributes (StructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1) SELECT @TargetStructureId, SomeId1, SomeId2, SomeBool1, SomeString, Created1 FROM Attributes WHERE StructureId = @SourceStructureId COMMIT END; And here’s an implementation of a replicator using this stored procedure: public class StoredProcedureReplicator : IReplicator { private readonly AppDbContext _dbContext; public StoredProcedureReplicator(AppDbContext dbContext) => _dbContext = dbContext; public async Task CopyStructureAsync(int sourceId, int targetId) { try { await _dbContext.Database.ExecuteSqlAsync( $"EXEC CopyStructure {sourceId}, {targetId}"); } catch { // handle } } } public class StoredProcedureReplicator : IReplicator { private readonly AppDbContext _dbContext; public StoredProcedureReplicator(AppDbContext dbContext) => _dbContext = dbContext; public async Task CopyStructureAsync(int sourceId, int targetId) { try { await _dbContext.Database.ExecuteSqlAsync( $"EXEC CopyStructure {sourceId}, {targetId}"); } catch { // handle } } } In the first article, we followed the path of logical reasoning about which of the two proposed approaches would run faster or be more optimal. Many of you, I am sure, need no more than a few seconds to answer this question. We’ve also looked at the reasons behind it. However, when it comes to real work, it is often not enough to know which approach is more performant. Pay your price If I imagine a situation where I go to my boss and say, for example, “Hey, we have never used stored procedures and raw SQL, but that would give us higher performance; let’s start using it,” the first thing he would ask would be, “How much higher?” and “What does it take to do that?”, which is the same as “What is the price?” Everything has its price. For C# and Java, the price of high portability is slightly lower performance compared to some other languages. For Rust, the price of memory safety is a steep learning curve and the relative complexity of the language itself is a challenge. For Go… hmm… I couldn’t come up with anything; it seems almost perfect. For our example, the price of introducing stored procedures will increase project complexity in a broad sense. You can also add vendor lock-in to a specific database to the list of drawbacks. Using raw SQL ties us to a specific dialect and reduces portability. I couldn’t come up with anything; it seems almost perfect. vendor lock-in There are obvious disadvantages. There are quite a few; they are known to you and should be known to your boss. So, the question “What justifies these introduced disadvantages?” is unlikely to be taken seriously with answers like “faster”, “more productive”, “more optimal”, “less resource intensive”, and “less memory”. Business likes specifics, and you and I like specifics too. Answers like “User wait time will drop from 4 seconds to 0.8 seconds” or “Our application will consume 10 percent less CPU time, which means we will save 1000 dollars per month” sound much more convincing and weightier. So, the “performance” that we want to “sell” to the boss and to ourselves must be significant enough to justify or offset the added complexity. To find out whether this is the case, we need to know objectively, in numbers, how large a gain the alternative solution provides. Tools We need to be familiar with profiling tools. The larger the set of tools you know, the better, since it gives you more flexibility. Sometimes, it is enough to put a Stopwatch around the place that interests us and print the result to the log. Sometimes, we do not know what place interests us and we run Visual Studio Profiler, PerfView, or dotTrace, which I prefer. Sometimes, we can test a couple of methods in isolation using BenchmarkDotNet, which, by the way, is not always possible. Stopwatch Also, when working with Entity Framework, it is necessary to understand what exact SQL your queries turn into. Various profilers like SQL Server Profiler or EF’s own tools can help with this. When working with the database, we can get the execution plan and statistics. I could go on and on about this topic - several books wouldn’t be enough to cover all the knowledge involved!!! So, I focused on a couple of such tools finally to understand how much the solution I proposed, using a stored procedure, works more efficiently than the solution that copies data back and forth with Entity Framework. EF → SQL Some people, especially beginners, think that using Entity Framework frees you from the need to know and use SQL. Unfortunately, this is far from true. At every moment, we must know what exact SQL code our chain of LINQ method calls is translated into. Otherwise, it is simply impossible to write efficient code. Entity Framework is an excellent library, though it can be unforgiving of mistakes. I will share with you a couple of instruments that will help you avoid mistakes. ToQueryString() Calling the ToQueryString() method on IQueryable<> will produce a string containing the SQL code to be executed. For the following code: ToQueryString() IQueryable<> await using AppContext dbContext = new(Configuration.ConnectionString); var queryable = dbContext.Nodes .Where(o => o.Id > 15) .Take(10) .Select(o => new { o.Id, o.Created1 }); Console.WriteLine(queryable.ToQueryString()); await using AppContext dbContext = new(Configuration.ConnectionString); var queryable = dbContext.Nodes .Where(o => o.Id > 15) .Take(10) .Select(o => new { o.Id, o.Created1 }); Console.WriteLine(queryable.ToQueryString()); the following SQL code will be generated: DECLARE @__p_0 int = 10; SELECT TOP(@__p_0) [n].[Id], [n].[Created1] FROM [Nodes] AS [n] WHERE [n].[Id] > 15 DECLARE @__p_0 int = 10; SELECT TOP(@__p_0) [n].[Id], [n].[Created1] FROM [Nodes] AS [n] WHERE [n].[Id] > 15 This is a handy way to pinpoint what’s going on. However, it only works for queries (SELECT), so it’s not suitable for understanding how our EntityFrameworkReplicator works. Run the test from the repo: SpOrNotSpPt2.Tests.ToQueryStringDemo.Get_Query_String_Then_Output SpOrNotSpPt2.Tests.ToQueryStringDemo.Get_Query_String_Then_Output LogTo() If we override the OnConfiguring() method in our context and call LogTo(Console.WriteLine) on the builder, then everything that happens under the EF hood will be visible in the console (you can use any logger you like). For me, it looks something like this: OnConfiguring() LogTo(Console.WriteLine) protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder) { optionsBuilder .UseSqlServer(_connectionString) .LogTo(Console.WriteLine, minimumLevel: LogLevel.Information) } protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder) { optionsBuilder .UseSqlServer(_connectionString) .LogTo(Console.WriteLine, minimumLevel: LogLevel.Information) } The following code await using AppContext dbContext = new(Configuration.ConnectionString); var queryable = dbContext.Nodes .Where(o => o.Id > 15) .Take(10) .Select(o => new { o.Id, o.Created1 }); var result = await queryable.ToArrayAsync(); await using AppContext dbContext = new(Configuration.ConnectionString); var queryable = dbContext.Nodes .Where(o => o.Id > 15) .Take(10) .Select(o => new { o.Id, o.Created1 }); var result = await queryable.ToArrayAsync(); will print something like this to the console: warn: 9/2/2025 13:56:11.488 CoreEventId.RowLimitingOperationWithoutOrderByWarning[10102] (Microsoft.EntityFrameworkCore.Query) The query uses a row limiting operator ('Skip'/'Take') without an 'OrderBy' operator. This may lead to unpredictable results. If the 'Distinct' operator is used after 'OrderBy', then make sure to use the 'OrderBy' operator after 'Distinct' as the ordering would otherwise get erased. info: 9/2/2025 13:56:11.873 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (50ms) [Parameters=[@__p_0='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SELECT TOP(@__p_0) [n].[Id], [n].[Created1] FROM [Nodes] AS [n] WHERE [n].[Id] > 15 warn: 9/2/2025 13:56:11.488 CoreEventId.RowLimitingOperationWithoutOrderByWarning[10102] (Microsoft.EntityFrameworkCore.Query) The query uses a row limiting operator ('Skip'/'Take') without an 'OrderBy' operator. This may lead to unpredictable results. If the 'Distinct' operator is used after 'OrderBy', then make sure to use the 'OrderBy' operator after 'Distinct' as the ordering would otherwise get erased. info: 9/2/2025 13:56:11.873 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (50ms) [Parameters=[@__p_0='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SELECT TOP(@__p_0) [n].[Id], [n].[Created1] FROM [Nodes] AS [n] WHERE [n].[Id] > 15 Pay attention to the first line, which has a warning. EF clearly let us know that our query has a problem with missing ordering. That’s pretty cool! Run the test from the repo: SpOrNotSpPt2.Tests.LogToDemo.Log_Writes_And_Reads SpOrNotSpPt2.Tests.LogToDemo.Log_Writes_And_Reads Log our Replicator After a short primer, let us see what happens when our EntityFrameworkReplicator works. We enable logging and start copying: EntityFrameworkReplicator await using AppContext dbContext = new(Configuration.ConnectionString); EntityFrameworkReplicator replicator = new(dbContext); await replicator.CopyStructureAsync(0, 1); await using AppContext dbContext = new(Configuration.ConnectionString); EntityFrameworkReplicator replicator = new(dbContext); await replicator.CopyStructureAsync(0, 1); In the logs, we will see the following: ... dbug: 9/2/2025 15:45:58.322 RelationalEventId.TransactionStarting[20209] (Microsoft.EntityFrameworkCore.Database.Transaction) Beginning transaction with isolation level 'Unspecified'. dbug: 9/2/2025 15:45:58.338 RelationalEventId.TransactionStarted[20200] (Microsoft.EntityFrameworkCore.Database.Transaction) Began transaction with isolation level 'ReadCommitted'. ... info: 9/2/2025 15:41:06.652 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (64ms) [Parameters=[@__sourceId_0='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SELECT [n].[Id], [n].[Created1], [n].[SomeBool1], [n].[SomeId1], [n].[SomeId2], [n].[SomeString], [n].[StructureId] FROM [Nodes] AS [n] WHERE [n].[StructureId] = @__sourceId_0 info: 9/2/2025 15:41:06.870 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (9ms) [Parameters=[@p0='?' (DbType = DateTimeOffset), @p1='?' (DbType = Boolean), @p2='?' (DbType = Int32), @p3='?' (DbType = Int32), @p4='?' (Size = 4000), @p5='?' (DbType = Int32), @p6='?' (DbType = DateTimeOffset), @p7='?' (DbType = Boolean), @p8='?' (DbType = Int32), @p9='?' (DbType = Int32), @p10='?' (Size = 4000), @p11='?' (DbType = Int32), @p12='?' (DbType = DateTimeOffset), @p13='?' (DbType = Boolean), @p14='?' (DbType = Int32), @p15='?' (DbType = Int32), @p16='?' (Size = 4000), @p17='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SET IMPLICIT_TRANSACTIONS OFF; SET NOCOUNT ON; MERGE [Nodes] USING ( VALUES (@p0, @p1, @p2, @p3, @p4, @p5, 0), (@p6, @p7, @p8, @p9, @p10, @p11, 1), (@p12, @p13, @p14, @p15, @p16, @p17, 2)) AS i ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId], _Position) ON 1=0 WHEN NOT MATCHED THEN INSERT ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId]) VALUES (i.[Created1], i.[SomeBool1], i.[SomeId1], i.[SomeId2], i.[SomeString], i.[StructureId]) OUTPUT INSERTED.[Id], i._Position; info: 9/2/2025 15:41:06.927 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (24ms) [Parameters=[@__sourceId_0='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SELECT [p].[Id], [p].[Created1], [p].[SomeBool1], [p].[SomeId1], [p].[SomeId2], [p].[SomeString], [p].[StructureId] FROM [Permissions] AS [p] WHERE [p].[StructureId] = @__sourceId_0 info: 9/2/2025 15:41:06.950 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (6ms) [Parameters=[@p0='?' (DbType = DateTimeOffset), @p1='?' (DbType = Boolean), @p2='?' (DbType = Int32), @p3='?' (DbType = Int32), @p4='?' (Size = 4000), @p5='?' (DbType = Int32), @p6='?' (DbType = DateTimeOffset), @p7 ='?' (DbType = Boolean), @p8='?' (DbType = Int32), @p9='?' (DbType = Int32), @p10='?' (Size = 4000), @p11='?' (DbType = Int32), @p12='?' (DbType = DateTimeOffset), @p13='?' (DbType = Boolean), @p14='?' (DbType = Int32), @p15='?' (DbType = Int32), @p16='?' (Size = 4000), @p17='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SET IMPLICIT_TRANSACTIONS OFF; SET NOCOUNT ON; MERGE [Permissions] USING ( VALUES (@p0, @p1, @p2, @p3, @p4, @p5, 0), (@p6, @p7, @p8, @p9, @p10, @p11, 1), (@p12, @p13, @p14, @p15, @p16, @p17, 2)) AS i ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId], _Position) ON 1=0 WHEN NOT MATCHED THEN INSERT ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId]) VALUES (i.[Created1], i.[SomeBool1], i.[SomeId1], i.[SomeId2], i.[SomeString], i.[StructureId]) OUTPUT INSERTED.[Id], i._Position; info: 9/2/2025 15:41:06.970 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (11ms) [Parameters=[@__sourceId_0='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SELECT [a].[Id], [a].[Created1], [a].[SomeBool1], [a].[SomeId1], [a].[SomeId2], [a].[SomeString], [a].[StructureId] FROM [Attributes] AS [a] WHERE [a].[StructureId] = @__sourceId_0 info: 9/2/2025 15:41:07.002 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (6ms) [Parameters=[@p0='?' (DbType = DateTimeOffset), @p1='?' (DbType = Boolean), @p2='?' (DbType = Int32), @p3='?' (DbType = Int32), @p4='?' (Size = 4000), @p5='?' (DbType = Int32), @p6='?' (DbType = DateTimeOffset), @p7 ='?' (DbType = Boolean), @p8='?' (DbType = Int32), @p9='?' (DbType = Int32), @p10='?' (Size = 4000), @p11='?' (DbType = Int32), @p12='?' (DbType = DateTimeOffset), @p13='?' (DbType = Boolean), @p14='?' (DbType = Int32), @p15='?' (DbType = Int32), @p16='?' (Size = 4000), @p17='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SET IMPLICIT_TRANSACTIONS OFF; SET NOCOUNT ON; MERGE [Attributes] USING ( VALUES (@p0, @p1, @p2, @p3, @p4, @p5, 0), (@p6, @p7, @p8, @p9, @p10, @p11, 1), (@p12, @p13, @p14, @p15, @p16, @p17, 2)) AS i ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId], _Position) ON 1=0 WHEN NOT MATCHED THEN INSERT ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId]) VALUES (i.[Created1], i.[SomeBool1], i.[SomeId1], i.[SomeId2], i.[SomeString], i.[StructureId]) OUTPUT INSERTED.[Id], i._Position; ... dbug: 9/2/2025 15:45:59.224 RelationalEventId.TransactionCommitting[20210] (Microsoft.EntityFrameworkCore.Database.Transaction) Committing transaction. dbug: 9/2/2025 15:45:59.243 RelationalEventId.TransactionCommitted[20202] (Microsoft.EntityFrameworkCore.Database.Transaction) Committed transaction. ... dbug: 9/2/2025 15:45:58.322 RelationalEventId.TransactionStarting[20209] (Microsoft.EntityFrameworkCore.Database.Transaction) Beginning transaction with isolation level 'Unspecified'. dbug: 9/2/2025 15:45:58.338 RelationalEventId.TransactionStarted[20200] (Microsoft.EntityFrameworkCore.Database.Transaction) Began transaction with isolation level 'ReadCommitted'. ... info: 9/2/2025 15:41:06.652 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (64ms) [Parameters=[@__sourceId_0='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SELECT [n].[Id], [n].[Created1], [n].[SomeBool1], [n].[SomeId1], [n].[SomeId2], [n].[SomeString], [n].[StructureId] FROM [Nodes] AS [n] WHERE [n].[StructureId] = @__sourceId_0 info: 9/2/2025 15:41:06.870 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (9ms) [Parameters=[@p0='?' (DbType = DateTimeOffset), @p1='?' (DbType = Boolean), @p2='?' (DbType = Int32), @p3='?' (DbType = Int32), @p4='?' (Size = 4000), @p5='?' (DbType = Int32), @p6='?' (DbType = DateTimeOffset), @p7='?' (DbType = Boolean), @p8='?' (DbType = Int32), @p9='?' (DbType = Int32), @p10='?' (Size = 4000), @p11='?' (DbType = Int32), @p12='?' (DbType = DateTimeOffset), @p13='?' (DbType = Boolean), @p14='?' (DbType = Int32), @p15='?' (DbType = Int32), @p16='?' (Size = 4000), @p17='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SET IMPLICIT_TRANSACTIONS OFF; SET NOCOUNT ON; MERGE [Nodes] USING ( VALUES (@p0, @p1, @p2, @p3, @p4, @p5, 0), (@p6, @p7, @p8, @p9, @p10, @p11, 1), (@p12, @p13, @p14, @p15, @p16, @p17, 2)) AS i ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId], _Position) ON 1=0 WHEN NOT MATCHED THEN INSERT ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId]) VALUES (i.[Created1], i.[SomeBool1], i.[SomeId1], i.[SomeId2], i.[SomeString], i.[StructureId]) OUTPUT INSERTED.[Id], i._Position; info: 9/2/2025 15:41:06.927 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (24ms) [Parameters=[@__sourceId_0='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SELECT [p].[Id], [p].[Created1], [p].[SomeBool1], [p].[SomeId1], [p].[SomeId2], [p].[SomeString], [p].[StructureId] FROM [Permissions] AS [p] WHERE [p].[StructureId] = @__sourceId_0 info: 9/2/2025 15:41:06.950 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (6ms) [Parameters=[@p0='?' (DbType = DateTimeOffset), @p1='?' (DbType = Boolean), @p2='?' (DbType = Int32), @p3='?' (DbType = Int32), @p4='?' (Size = 4000), @p5='?' (DbType = Int32), @p6='?' (DbType = DateTimeOffset), @p7 ='?' (DbType = Boolean), @p8='?' (DbType = Int32), @p9='?' (DbType = Int32), @p10='?' (Size = 4000), @p11='?' (DbType = Int32), @p12='?' (DbType = DateTimeOffset), @p13='?' (DbType = Boolean), @p14='?' (DbType = Int32), @p15='?' (DbType = Int32), @p16='?' (Size = 4000), @p17='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SET IMPLICIT_TRANSACTIONS OFF; SET NOCOUNT ON; MERGE [Permissions] USING ( VALUES (@p0, @p1, @p2, @p3, @p4, @p5, 0), (@p6, @p7, @p8, @p9, @p10, @p11, 1), (@p12, @p13, @p14, @p15, @p16, @p17, 2)) AS i ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId], _Position) ON 1=0 WHEN NOT MATCHED THEN INSERT ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId]) VALUES (i.[Created1], i.[SomeBool1], i.[SomeId1], i.[SomeId2], i.[SomeString], i.[StructureId]) OUTPUT INSERTED.[Id], i._Position; info: 9/2/2025 15:41:06.970 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (11ms) [Parameters=[@__sourceId_0='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SELECT [a].[Id], [a].[Created1], [a].[SomeBool1], [a].[SomeId1], [a].[SomeId2], [a].[SomeString], [a].[StructureId] FROM [Attributes] AS [a] WHERE [a].[StructureId] = @__sourceId_0 info: 9/2/2025 15:41:07.002 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command) Executed DbCommand (6ms) [Parameters=[@p0='?' (DbType = DateTimeOffset), @p1='?' (DbType = Boolean), @p2='?' (DbType = Int32), @p3='?' (DbType = Int32), @p4='?' (Size = 4000), @p5='?' (DbType = Int32), @p6='?' (DbType = DateTimeOffset), @p7 ='?' (DbType = Boolean), @p8='?' (DbType = Int32), @p9='?' (DbType = Int32), @p10='?' (Size = 4000), @p11='?' (DbType = Int32), @p12='?' (DbType = DateTimeOffset), @p13='?' (DbType = Boolean), @p14='?' (DbType = Int32), @p15='?' (DbType = Int32), @p16='?' (Size = 4000), @p17='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30'] SET IMPLICIT_TRANSACTIONS OFF; SET NOCOUNT ON; MERGE [Attributes] USING ( VALUES (@p0, @p1, @p2, @p3, @p4, @p5, 0), (@p6, @p7, @p8, @p9, @p10, @p11, 1), (@p12, @p13, @p14, @p15, @p16, @p17, 2)) AS i ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId], _Position) ON 1=0 WHEN NOT MATCHED THEN INSERT ([Created1], [SomeBool1], [SomeId1], [SomeId2], [SomeString], [StructureId]) VALUES (i.[Created1], i.[SomeBool1], i.[SomeId1], i.[SomeId2], i.[SomeString], i.[StructureId]) OUTPUT INSERTED.[Id], i._Position; ... dbug: 9/2/2025 15:45:59.224 RelationalEventId.TransactionCommitting[20210] (Microsoft.EntityFrameworkCore.Database.Transaction) Committing transaction. dbug: 9/2/2025 15:45:59.243 RelationalEventId.TransactionCommitted[20202] (Microsoft.EntityFrameworkCore.Database.Transaction) Committed transaction. Put simply, here’s the gist of it: Start a transaction. Select Nodes, then insert Nodes. Select Permissions, then insert Permissions. Select Attributes, then insert Attributes. Finish the transaction. Start a transaction. Select Nodes, then insert Nodes. Select Permissions, then insert Permissions. Select Attributes, then insert Attributes. Finish the transaction. Everything is as the first article predicted, with no surprises. Though it is interesting that for the insert EF generated MERGE, people say EF is dumb, but to me, it looks quite smart. MERGE By the way, LogTo() has several logging levels, and you need to play with them a bit to understand which one suits you. For example, at the LogLevel.Information level, you will see SQL code, but you will not see information about transactions - for that, you need LogLevel.Debug. LogTo() LogLevel.Information LogLevel.Debug Connection Statistics There is a very simple, but sometimes incredibly useful, tool for collecting connection information. It may be useful for you to learn about it if you are not already familiar with it. To work with the database, regardless of whether you use EF, Dapper, SqlClient, LINQ to SQL, or something else, you need an instance of SqlConnection. SqlConnection has a statistics collection feature that we will now use to compare EntityFrameworkReplicator and StoredProcedureReplicator. In general, it looks like this: SqlConnection SqlConnection EntityFrameworkReplicator StoredProcedureReplicator await using SqlConnection connection = new(Configuration.ConnectionString) { StatisticsEnabled = true }; // work with db here... // retrieve statistics foreach (DictionaryEntry stat in connection.RetrieveStatistics()) { Console.WriteLine($"{stat.Key} : {stat.Value}"); } await using SqlConnection connection = new(Configuration.ConnectionString) { StatisticsEnabled = true }; // work with db here... // retrieve statistics foreach (DictionaryEntry stat in connection.RetrieveStatistics()) { Console.WriteLine($"{stat.Key} : {stat.Value}"); } That is, to get the statistics, all we need to do is call RetrieveStatistics and iterate the result. RetrieveStatistics The code for our comparison: ... await using SqlConnection connection = new(Configuration.ConnectionString); connection.StatisticsEnabled = true; await using AppContext context = new(connection); await new EntityFrameworkReplicator(context).CopyStructureAsync(0, 1); foreach (DictionaryEntry stat in connection.RetrieveStatistics()) { Console.WriteLine($"{stat.Key} : {stat.Value}"); } connection.ResetStatistics(); await new StoredProcedureReplicator(context).CopyStructureAsync(0, 1); foreach (DictionaryEntry stat in connection.RetrieveStatistics()) { Console.WriteLine($"{stat.Key} : {stat.Value}"); } ... ... await using SqlConnection connection = new(Configuration.ConnectionString); connection.StatisticsEnabled = true; await using AppContext context = new(connection); await new EntityFrameworkReplicator(context).CopyStructureAsync(0, 1); foreach (DictionaryEntry stat in connection.RetrieveStatistics()) { Console.WriteLine($"{stat.Key} : {stat.Value}"); } connection.ResetStatistics(); await new StoredProcedureReplicator(context).CopyStructureAsync(0, 1); foreach (DictionaryEntry stat in connection.RetrieveStatistics()) { Console.WriteLine($"{stat.Key} : {stat.Value}"); } ... I got two tables as an output. Then, for convenience, I merged them into one (by the way, you can see the improved version of the code in the project on GitHub). Metrics EntityFramework Stored procedure BuffersReceived 8 1 BuffersSent 8 1 BytesReceived 2184 129 BytesSent 7873 174 CursorOpens 0 0 IduCount 3 3 IduRows 0 9 PreparedExecs 0 0 Prepares 0 0 SelectCount 3 0 SelectRows 9 0 ServerRoundtrips 8 1 SumResultSets 6 0 Transactions 1 1 UnpreparedExecs 6 1 ConnectionTime 166 28 ExecutionTime 12 0 NetworkServerTime 51 28 Metrics EntityFramework Stored procedure BuffersReceived 8 1 BuffersSent 8 1 BytesReceived 2184 129 BytesSent 7873 174 CursorOpens 0 0 IduCount 3 3 IduRows 0 9 PreparedExecs 0 0 Prepares 0 0 SelectCount 3 0 SelectRows 9 0 ServerRoundtrips 8 1 SumResultSets 6 0 Transactions 1 1 UnpreparedExecs 6 1 ConnectionTime 166 28 ExecutionTime 12 0 NetworkServerTime 51 28 Metrics EntityFramework Stored procedure Metrics Metrics EntityFramework EntityFramework Stored procedure Stored procedure BuffersReceived 8 1 BuffersReceived BuffersReceived 8 8 1 1 BuffersSent 8 1 BuffersSent BuffersSent 8 8 1 1 BytesReceived 2184 129 BytesReceived BytesReceived 2184 2184 129 129 BytesSent 7873 174 BytesSent BytesSent 7873 7873 174 174 CursorOpens 0 0 CursorOpens CursorOpens 0 0 0 0 IduCount 3 3 IduCount IduCount 3 3 3 3 IduRows 0 9 IduRows IduRows 0 0 9 9 PreparedExecs 0 0 PreparedExecs PreparedExecs 0 0 0 0 Prepares 0 0 Prepares Prepares 0 0 0 0 SelectCount 3 0 SelectCount SelectCount 3 3 0 0 SelectRows 9 0 SelectRows SelectRows 9 9 0 0 ServerRoundtrips 8 1 ServerRoundtrips ServerRoundtrips 8 8 1 1 SumResultSets 6 0 SumResultSets SumResultSets 6 6 0 0 Transactions 1 1 Transactions Transactions 1 1 1 1 UnpreparedExecs 6 1 UnpreparedExecs UnpreparedExecs 6 6 1 1 ConnectionTime 166 28 ConnectionTime ConnectionTime 166 166 28 28 ExecutionTime 12 0 ExecutionTime ExecutionTime 12 12 0 0 NetworkServerTime 51 28 NetworkServerTime NetworkServerTime 51 51 28 28 We see a huge difference in the number of bytes transferred, in the number of round trips, in execution time, and so on… Everything as we expected. And this is only for three rows in each of our three tables. So, it’s quite easy to implement the logging of these statistics in the necessary place or filter out only the metrics you’re interested in. In my opinion, it is a very underrated thing. Run the test from the repo: SpOrNotSpPt2.Tests.ConnectionStatisticsDemo.Collect_Connection_Statistics_For_Ef_And_Sp_Replicators SpOrNotSpPt2.Tests.ConnectionStatisticsDemo.Collect_Connection_Statistics_For_Ef_And_Sp_Replicators Finale: BenchmarkDotNet The cherry on top is the performance comparison using BenchmarkDotNet. (If you are unfamiliar with it, you should definitely check it out at benchmarkdotnet.org.) benchmarkdotnet.org I would like to emphasize once again that it is not always possible to “bolt on” BenchmarkDotNet and measure a piece of code from an existing project. You may be hindered by dependencies, injections, or other things. In such a case, it is worth turning to something like dotTrace or dotMemory. Fortunately, for our example, it fits perfectly. The measurement was performed using SQL Server 2022 running in a Docker container on the same machine as the test. It means that in real conditions everything can be much worse if the database is located somewhere in the network. But even such a test is very illustrative. on the same machine The benchmark report is here. here A small note. NumberOfRecords is the number of records of one entity, and we have three such entities, so multiply it by three to get the total number of rows. A small note. NumberOfRecords I doubt that this chart requires any comments. The stored procedure, together with raw SQL, looks almost constant against the background of Entity Framework. Of course, this is not literally so; however, the rate of growth is much lower than that of Entity Framework. In fact, the stored procedure slows down as record counts rise, which is logical, but the gap with the inefficient approach remains enormous. When the NumberOfRecords equals 3, the difference in duration is approximately 3 times; for 12, the difference is already 6 times; and for 192, the difference is already 12 times. Not to mention memory. As we see, memory consumption grows for Entity Framework but remains constant for the stored procedure and raw SQL. NumberOfRecords As a demonstration and for greater clarity, I excluded EF from the next chart. We can see that memory consumption does not change at all, just as we expected. By the way, at this scale, the slowdown looks much more expressive, depending on the number of records. looks A large scale, as in the first chart, can often visually swallow information about small numbers. The big picture may not reflect the picture in a narrow, local case. However, the conclusions I have been nudging you toward since the very beginning of the first article remain valid, even for very small numbers. Here’s one more chart in the 0-6 range for demonstration. For the stored procedure, we cannot even see the memory consumption column because it is so insignificant. We could perform exactly the same measurement but using a remote database. You could look at the results with some SQLite; that would also be interesting. Unfortunately, in my opinion, I’ve already exhausted every conceivable limit on article length. If you’re interested in that type of thing, you can pick up my repository and play with it yourself. Conclusion As in the previous article, I want to emphasize that I am not pushing anyone toward anything. I’m just sharing the tools that I myself use on a daily basis, and you can choose the tools that work best for you. The most important tool is, of course, your mind. It is perfect for making an initial analysis and coming to certain conclusions. The first article was devoted to that kind of analysis. However, this approach is not always suitable. If you conclude that some code is faster than other code, it may not be sufficient on its own without additional information. How much faster is it? How much harder is it to implement? Is the first (speed of execution) worth the second (added complexity)? While the second point is very complicated - it is quite difficult to express “complexity” objectively - there is no problem with the first one. You just need to count bytes, milliseconds, clock cycles, the percentage of CPU peaks, the number of consumed threads and sockets (and so on) for both solutions and compare them. It is up to you to decide what to do based on the collected data.