2

I've started to use the QueryStore to monitor my App and one of the things I noticed is the unexpected high memory usage for what I thought a simple operation:

enter image description here

Which would mean the statement uses almost 600MB of RAM each time it is executed?
The RowCount for each execution in that timeframe is a lot less than 100. The Statement itself is run every 5 seconds.

The Table is partitioned and based on a ColumnStore Index and has no other Indexes or Primary Key/Identity and has around 750k Rows:

CREATE TABLE [DataLink].[LogEntry](
  [AppInstanceId] [bigint] NOT NULL,
  [LoggedOnUtc] [datetime2](7) NOT NULL,
  [CategoryName] [nvarchar](256) NOT NULL,
  [EventCode] [int] NOT NULL,
  [EventName] [nvarchar](256) NULL,
  [LogLevel] [int] NOT NULL,
  [ScopeJson] [nvarchar](max) NULL,
  [StateJson] [nvarchar](max) NULL,
  [ExceptionJson] [nvarchar](max) NULL,
  [Message] [nvarchar](max) NULL
) ON [PSCH_Logging_DataLink_LogEntry_Daily7Of9]([LoggedOnUtc])

CREATE CLUSTERED COLUMNSTORE INDEX [CIX_LogEntry] 
ON [DataLink].[LogEntry] WITH (DROP_EXISTING = OFF, COMPRESSION_DELAY = 0, DATA_COMPRESSION = COLUMNSTORE) 
ON [PSCH_Logging_DataLink_LogEntry_Daily7Of9]([LoggedOnUtc])

The Code which triggers the inserts:

using var conn = connInfo.Main.GetConnection(DatabaseLoginType.User);
await conn.OpenAsync(ct).CAf();
using var sqlBulkCopy = new SqlBulkCopy((SqlConnection)conn, SqlBulkCopyOptions.CheckConstraints | SqlBulkCopyOptions.FireTriggers, null);

foreach(var toWriteItemGroup in toWriteItems.GroupBy(x => x.SchemaName)) {
...

    dataReader.Init(toWriteItemGroup, tableInfo.ColumnMappings.Length);

    sqlBulkCopy.DestinationTableName = $"{schemaName}.LogEntry";
    sqlBulkCopy.ColumnMappings.Clear();
    for(int i = 0; i < tableInfo.ColumnMappings.Length; i++) sqlBulkCopy.ColumnMappings.Add(i, tableInfo.ColumnMappings[i]);
    await sqlBulkCopy.WriteToServerAsync(dataReader, ct).CAf();
...
}

Any idea why the memory usage is so high and what I could do to fix that?

Edit4
I did some tests by changing and manually compiling Microsoft.Data.SqlClient. The changes I made included adding ROWS_PER_BATCH and/or KILOBYTES_PER_BATCH to the with options of the "insert bulk" statement. None of the options changed how much memory was used, the former changed the row count estimate though: https://www.brentozar.com/pastetheplan/?id=HkKjc9HIC It doesn't seem like "insert bulk" can be optimized for low row counts.

Edit3
Here is a short example with which I can reproduce the issue.
It contains a script "Script.sql" which needs to be executed first to setup the table and add some data. After that run the program with "dotnet run" (or use an IDE).
Since I can't upload files here, I've uploaded it to github gist: https://gist.github.com/DvdKhl/d042ed05e3237136265295cb39ecb4f4

The Script will:

  • Create a view, which shows PartitionInfo of the table
  • Create (or recreate) the Table and it configuration
  • Insert 700k rows (100k per partition)
  • Rebuild the index
  • Output the Partition Info
  • Commented out is
    • Event Session (Extended Event) to capture the query plan
    • Another insert Statement
    • Cleanup

The Program will:

  • Open a connection on "localhost" for the DB "main"
  • Create a Dummy DataReader (Change Count to change the inserted row count)
  • Setup SqlBulkCopy like above
  • Call WriteToServerAsync to insert the rows

This results in the following queryplan: https://www.brentozar.com/pastetheplan/?id=B1v_8bGLC

Edit2
Like Suggested by Denis Rubashkin I've set BatchSize and an order hint:

sqlBulkCopy.BatchSize = toWriteItemGroup.Count();
sqlBulkCopy.ColumnOrderHints.Add("LoggedOnUtc", SortOrder.Ascending);

BatchSize doesn't seem to change anything (the estimate stays the same).
It looks like ROWS_PER_BATCH is not used even though sqlBulkCopy.BatchSize is set in the code, which might be the main problem.

When the Order hint is added, the query does not show up in the QueryStore.
Using extended events to get the queryplan shows an "Excessive Grant" Warning though. So I'm not sure it helped.

The option KILOBYTES_PER_BATCH looks interesting but it does not seem like I can set it in the C# code.

WithOrderHint / WithoutOrderHint (Different table but exactly the same problem)

Edit:
Queryplan: https://www.brentozar.com/pastetheplan/?id=SJGpBktH0

Table Properties - Storage
enter image description here

Disk Usage by Partition
enter image description here

1
  • The log table can get quite large and I need to be able to drop old partitions quickly Most of the time insert row count is small but it might be a lot higher in some situations
    – Arokh
    Commented Jun 13 at 21:48

3 Answers 3

3
+100

I did a test

I've created three tables

  • Clustered columnstore
  • Clustered index
  • Heap

And ran a bcp tool against 3 of them while looking in the Query Store

Repro

CREATE DATABASE BulkCopy
GO
USE BulkCopy
go
ALTER DATABASE [BulkCopy] SET QUERY_STORE CLEAR

DROP TABLE IF EXISTS dbo.OrderItemCCX
CREATE TABLE dbo.OrderItemCCX
(
    Id int IDENTITY (1,1) NOT NULL
    , OrderId int NOT NULL
    , ProductName varchar(50) NOT NULL
    , Qty int NOT NULL

)
GO
    CREATE CLUSTERED COLUMNSTORE INDEX [CCX_OrderItemCCX]
ON dbo.OrderItemCCX WITH (DROP_EXISTING = OFF, COMPRESSION_DELAY = 0, DATA_COMPRESSION = COLUMNSTORE) 
GO

DROP TABLE IF EXISTS dbo.OrderItemHeap
go
CREATE TABLE dbo.OrderItemHeap
(
    Id int IDENTITY (1,1) NOT NULL
    , OrderId int NOT NULL
    , ProductName varchar(50) NOT NULL
    , Qty int NOT NULL

)

go
DROP TABLE IF EXISTS dbo.OrderItemCX
go
CREATE TABLE dbo.OrderItemCX
(
    Id int IDENTITY (1,1) NOT NULL
    , OrderId int NOT NULL
    , ProductName varchar(50) NOT NULL
    , Qty int NOT NULL
    , CONSTRAINT PK_OrderItem PRIMARY KEY CLUSTERED (Id)
)
GO

I've stored this as a csv file on my local disk D:\OrderItems.csv

,4,abcd,42
,4,asdasd,42
,5,asdasdasd,42
,5,dhdrh,42
,5,dasd,42
,6,fdhg,42
,4,abcd,42
,4,asdasd,42
,5,asdasdasd,42
,5,dhdrh,42
,5,dasd,42
,6,fdhg,42
,4,abcd,42
,4,asdasd,42
,5,asdasdasd,42
,5,dhdrh,42
,5,dasd,42
,6,fdhg,42
,4,abcd,42
,4,asdasd,42

And ran bcp in a 5 sec loop with PowerShell (change the target table to one of the three above)

while ($true) {
    # Run the bcp command
    & bcp dbo.OrderItemCCX in "D:\OrderItems.csv" -S localhost -d BulkCopy -T -c -t ','
    
    Start-Sleep -Seconds 5
}

Later I also added the LogEntry table (albeit not partitioned) with some chatGPT-generated data

DROP TABLE IF EXISTS dbo.LogEntry

CREATE TABLE dbo.LogEntry
(
    AppInstanceId bigint        NOT NULL
  , LoggedOnUtc   datetime2(7)  NOT NULL
  , CategoryName  nvarchar(256) NOT NULL
  , EventCode     int           NOT NULL
  , EventName     nvarchar(256) NULL
  , LogLevel      int           NOT NULL
  , ScopeJson     nvarchar(MAX) NULL
  , StateJson     nvarchar(MAX) NULL
  , ExceptionJson nvarchar(MAX) NULL
  , Message       nvarchar(MAX) NULL
)

CREATE CLUSTERED COLUMNSTORE INDEX [CIX_LogEntry] 
ON dbo.LogEntry WITH (DROP_EXISTING = OFF, COMPRESSION_DELAY = 0, DATA_COMPRESSION = COLUMNSTORE) 
1,2024-06-01 12:00:00.0000000,Application,1001,Startup,1,scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app,init-state-init-state-init-state-init-state-init-state-init-state-init-state-init-state-init-state-init,,Application started successfully.
2,2024-06-01 12:05:00.0000000,Application,1002,Shutdown,1,scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app,shutdown-state-shutdown-state-shutdown-state-shutdown-state-shutdown-state-shutdown-state-shutdown,,Application shutdown initiated.
3,2024-06-01 12:10:00.0000000,Security,2001,Login,2,scope-user-scope-user-scope-user-scope-user-scope-user-scope-user-scope-user-scope-user-scope-user,login-state-login-state-login-state-login-state-login-state-login-state-login-state-login-state-login,,User login successful.
4,2024-06-01 12:15:00.0000000,Security,2002,Logout,2,scope-user-scope-user-scope-user-scope-user-scope-user-scope-user-scope-user-scope-user-scope-user,logout-state-logout-state-logout-state-logout-state-logout-state-logout-state-logout-state-logout-state-logout,,User logout successful.
5,2024-06-01 12:20:00.0000000,Database,3001,Connection,3,scope-db-scope-db-scope-db-scope-db-scope-db-scope-db-scope-db-scope-db-scope-db-scope-db,connected-state-connected-state-connected-state-connected-state-connected-state-connected-state-connected-state-connected,,Database connection established.
6,2024-06-01 12:25:00.0000000,Database,3002,Disconnection,3,scope-db-scope-db-scope-db-scope-db-scope-db-scope-db-scope-db-scope-db-scope-db-scope-db,disconnected-state-disconnected-state-disconnected-state-disconnected-state-disconnected-state-disconnected-state-disconnected,,Database connection closed.
7,2024-06-01 12:30:00.0000000,Error,4001,Exception,4,scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app,error-state-error-state-error-state-error-state-error-state-error-state-error-state-error-state-error-state-error-state,error-NullReferenceException-error-NullReferenceException-error-NullReferenceException-error-NullReferenceException,An unexpected error occurred.
8,2024-06-01 12:35:00.0000000,Performance,5001,HighCPU,2,scope-system-scope-system-scope-system-scope-system-scope-system-scope-system-scope-system-scope-system-scope-system,warning-state-warning-state-warning-state-warning-state-warning-state-warning-state-warning-state-warning-state-warning,,High CPU usage detected.
9,2024-06-01 12:40:00.0000000,Performance,5002,HighMemory,2,scope-system-scope-system-scope-system-scope-system-scope-system-scope-system-scope-system-scope-system-scope-system,warning-state-warning-state-warning-state-warning-state-warning-state-warning-state-warning-state-warning-state-warning,,High memory usage detected.
10,2024-06-01 12:45:00.0000000,Application,1003,Update,1,scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app-scope-app,update-state-update-state-update-state-update-state-update-state-update-state-update-state-update-state-update,,Application update completed.

Results

These are the results from the Query Store (don't mind the two rows per start time, that's because the time bucket isn't closed yet)

SELECT 
    qsq.query_id
    , qsp.plan_id
    , LEFT(qsqt.query_sql_text, 30) AS QueryText
    , CONVERT(VARCHAR(8), qsrsi.start_time, 108) AS start_time
    , qsrs.count_executions
    , qsrs.avg_rowcount
    , qsrs.avg_query_max_used_memory   /* KiB */
    , qsrs.last_query_max_used_memory  /* KiB */
    , qsrs.min_query_max_used_memory   /* KiB */
    , qsrs.max_query_max_used_memory   /* KiB */
FROM sys.query_store_query AS qsq
JOIN sys.query_store_query_text AS qsqt
    ON qsqt.query_text_id = qsq.query_text_id
JOIN sys.query_store_plan AS qsp
    ON qsp.query_id = qsq.query_id
JOIN sys.query_store_runtime_stats AS qsrs
    ON qsrs.plan_id = qsp.plan_id
JOIN sys.query_store_runtime_stats_interval AS qsrsi
    ON qsrsi.runtime_stats_interval_id = qsrs.runtime_stats_interval_id
WHERE qsqt.query_sql_text LIKE 'insert bulk%'
ORDER BY qsrsi.start_time, qsq.query_id

enter image description here

Takeaways

As we can see, only bulk inserts into the columnstore have large memory usage. LogEntry also has larger usage than OrderItemCCX - that could be based on the data size or columnstore segments (more columns).

At any rate, inserting 20 rows per batch doesn't strike me as a job for bulk copy.

I recommend reading through Columnstore indexes - Data loading guidance and perhaps using a staging table approach.

1
  • I agree, that for that few rows "insert bulk" might be overkill but I'm surprised it performs this bad. Going by your last table, it uses 15231*8/1024=118MiB (Columns are counts of 8KiB Pages) even for the non columnstore table. This is probably due to the ROWS_PER_BATCH option not being set as I've found out in Edit3. I'll probably create an issue at github for it because I'm very curious as to why that option is not set when BatchSize is set. I've read that " Columnstore indexes" page and a staging table would be too complex for my purposes.
    – Arokh
    Commented Jun 21 at 7:26
3

Bulk insert is optimized for bulk inserts. With a clustered columnstore target, this means in particular that the memory grant is sized to allow the production of compressed row groups, which can be very memory intensive.

You might only intend to insert a small number of rows, and you can convince the optimizer to generate a plan optimized for a small number of rows BUT the bulk insert memory grant will still be large because a large number of rows might be encountered at runtime.

Another way to look at it is, if you were only going to insert a small number of rows you wouldn't be using bulk insert. It's a reasonable inference for SQL Server to make.

Workaround

All that said, it is undeniably convenient to use SqlBulkCopy from code. If you want to keep your existing arrangement largely intact but achieve trickle inserts, one workaround is to use a trigger.

Now, you can't create a trigger on a clustered columnstore table directly, but you can create one on a view of a clustered columnstore table.

Making the trigger an INSTEAD OF insert trigger allows us to convert the bulk insert into a trickle insert.

Example

CREATE VIEW dbo.LogEntryInsertAdapter
WITH SCHEMABINDING AS
SELECT 
    AppInstanceId,
    LoggedOnUtc,
    CategoryName,
    EventCode,
    EventName,
    LogLevel,
    ScopeJson,
    StateJson,
    ExceptionJson,
    [Message] 
FROM dbo.LogEntry;
GO
CREATE TRIGGER LogEntryInsertAdapter_IOI
ON dbo.LogEntryInsertAdapter 
INSTEAD OF INSERT
AS
SET NOCOUNT ON;
INSERT dbo.LogEntry SELECT * FROM Inserted;
GO

The only code change required is:

sqlBulkCopy.DestinationTableName = $"dbo.LogEntryInsertAdapter";

Your demo code then results in an insert with no memory grant:

view insert

Strictly, that's an insert to a hidden temporary table. The real insert performed by the trigger is:

table insert

That also has a zero memory grant.

For those occasions where you have a large number of rows and want to perform a bulk insert, target the original table name instead of the view (or omit SqlBulkCopyOptions.FireTriggers).

1

The Sort operator is the only operator which needs memory in the attached query plan I can see. What looks weird for me is that zero memory usage declared inside the plan:

<MemoryGrantInfo SerialRequiredMemory="0" SerialDesiredMemory="0" GrantedMemory="0" MaxUsedMemory="0" />

Perhaps the server needs some memory to work with binary data from your app or that is just some feature of an "insert bulk" queries' plans. Anyway, I guess such big memory grant is because of wrong estimation (10000) in the Remote Scan operator.

You can try to add hint ROWS_PER_BATCH = rows_per_batch to improve estimation, and/or add hint ORDER LoggedOnUtc ASC to avoid the Sort operator in the query plan.

Have a look at External tool only syntax

Hope this helps.

0

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.