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:
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
-
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 situationsArokh– Arokh2024年06月13日 21:48:51 +00:00Commented Jun 13, 2024 at 21:48
3 Answers 3
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
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.
-
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– Arokh2024年06月21日 07:26:09 +00:00Commented Jun 21, 2024 at 7:26
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:
Strictly, that's an insert to a hidden temporary table. The real insert performed by the trigger is:
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
).
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.
Explore related questions
See similar questions with these tags.