Last night we upgraded a SQL Server 2012 server to SQL Server 2017 + CU 29. This is one of a matched set - we send the same message to both and each processes it. No, this is not AlwaysOn; we're using MSMQ to send the messages. This server was the first to be upgraded to 2017, the newest we could get to on that version of Windows. it is a physical box with 64gb of RAM and 2 E52650s running with hyperthreading on.
Since the upgrade, we've been having large performance issues, largely around LCK_M_IX waits on the insert into the hourly tables that the activated stored procedure writes to (messages come in, we parse the EDI and write to a series of tables for later use - it's only ever writes, no updates).
To try and fix it (upwards of 90k ms waits on LCK_M_IX shown in SP_WHOISACTUIVE) we dropped the threads from 30 to 15, and also moved to Compatability Level 140 and the new cardinality estimator (we had tried going back to see if it solved the blocking issue). We were able to raise the threads to 20; the machine has plenty of cores left. Note that the other server, still on SQL Server 2012, is NOT having any of these issues (they're both having a performance issue after a weekend, that's why we're upgrading)
Now, we seem to be doing good performance-wise, UNTIL it starts inserting into the next hour, at which point we see LCK_M_IX waits again. We dropped the fillfactor from 95 to 70 for the tables and also ran a specific UPDATE STATISTICS WITH FULLSCAN on the tables, but we still had it occur.
This last time, when we saw the locks, I ran:
UPDATE STATISTICS <mytablename> WITH FULLSCAN
go
dbcc freeproccache
go
dbcc dropcleanbuffers
between all of them, the blocking went away about 30s-60s later. Unsure what the actual fix was; when the next hour finishes, if it happens again, I'll do them separated by more than a minute to see if I can figure out what's going on.
UPDATE AN HOUR LATER: it was blocking. after a few minutes, since it wasn't going to fix itself, we ran UPDATE STATISTICS on the new table it's writing to, and 3 minutes later the blocking stopped. Still not sustainable, but we didn't need a FREEPROCCACHE or DROPCLEANBUFFERS.
Update two hours later: Had to do a FREEPROCCACHE to get it to work this time. Unsure why the stats updates were working before. I have no idea.
I now have info from query store. It says that for the insert, the first couple hundred times it runs, grabs plan 36384. That is "table valued function->compute scalar->compute scalar->table insert->sort->index insert->insert. But it only does a few hundred inserts then, because of the way our queues are working. Then it does nothing for the better part of an hour, and when it starts up again the existing plan goes from having a max duration of 5ms to a max duration of 82000ms and the average goes from 1.79ms to 400ms, std dev of 5500ms. It then uses that plan for 30k before I finally kick it out. When I do a freeproccache, the new plan generated (49980) is "Table Valued Function->Computer Scalar->Compute Scalar->Table Insert->Index Insert->Insert", and it proceeds to use that for about 500k times, with an average of 1.85ms and a max of 304ms, stdev of 2.5ms.
So for some reason that SORT prior to it appears to be causing the issue. But since each hour has its own table, how do I get it to insert properly?
Update several days later: Plans!
- good plan: https://www.brentozar.com/pastetheplan/?id=r190pFk95
- bad plan: https://www.brentozar.com/pastetheplan/?id=SJQmk5yq5
(note that there are a couple cardinality warnings. Actually, it's every field that comes out of that CLR function on the right, but since there are like 200 fields and SQL Sentry Plan Explorer doesn't anonymize it, I cut it down and did it manually for two fields)
Also: an ugly fix! If we manually update the stats for the tables we're writing to, it no longer has issues. The downside is I need to make sure that later maintenance doesn't "fix" it.
UPDATE STATISTICS [dbo].[tablea_20220621_10] WITH ROWCOUNT=100000, PAGECOUNT=12318;
UPDATE STATISTICS [dbo].[tablea_20220621_10] ([ncidx_20220621_10_request_id]) WITH ROWCOUNT=100000, PAGECOUNT=314;
Full gallery: https://imgur.com/gallery/dvTBbP9
Here's the basic definition for the table (there's a total of 200 fields, there's only one index and it's on the IDENTITY, but is nonclustered.)
CREATE TABLE mytablename
(
[ID] [bigint] NOT NULL IDENTITY(1, 1),
[BUNDLE_ID] [bigint] NOT NULL,
[TX_NUMBER] [bigint] NOT NULL,
[SEQUENCE_NUMBER] [bigint] NULL,
[DATE_SWITCHED] [datetime] NULL,
...bunch of fields deleted
) ON [PRIMARY]
GO
CREATE NONCLUSTERED INDEX [ncidx_mytable_id] ON [mytablename] ([ID]) WITH (FILLFACTOR=70) ON [PRIMARY]
GO
Obviously, this isn't sustainable, but I'm unsure where to go from here. When I looked earlier to see what the object was that was having issues, I did a DBCC PAGE and got the below part.
PAGE: (1:11671680)
BUFFER:
BUF @0x000000F9F30AB040
bpage = 0x00000109781C2000 bhash = 0x0000000000000000 bpageno = (1:11671680)
bdbid = 7 breferences = 3 bcputicks = 0
bsampleCount = 0 bUse1 = 64097 bstat = 0x9
blog = 0xab21215a bnext = 0x0000000000000000 bDirtyContext = 0x0000000000000000
bstat2 = 0x0
PAGE HEADER:
Page @0x00000109781C2000
m_pageId = (1:11671680) m_headerVersion = 1 m_type = 2
m_typeFlagBits = 0x0 m_level = 0 m_flagBits = 0x200
m_objId (AllocUnitId.idObj) = 616874m_indexId (AllocUnitId.idInd) = 256
Metadata: AllocUnitId = 72057634465382400 Metadata: PartitionId = 0
Metadata: IndexId = -1 Metadata: ObjectId = 0 m_prevPage = (1:11669448)
m_nextPage = (5:1189096) pminlen = 17 m_slotCnt = 204
m_freeCnt = 3608 m_freeData = 4336 m_reservedCnt = 0
m_lsn = (12098536:210111:57) m_xactReserved = 0 m_xdesId = (11:-563572576)
m_ghostRecCnt = 4 m_tornBits = -230377116 DB Frag ID = 1
Allocation Status
GAM (1:11247104) = NOT ALLOCATED SGAM (1:11247105) = NOT ALLOCATED PFS (1:11670984) = 0x8 0_PCT_FULL
DIFF (1:11247110) = CHANGED ML (1:11247111) = NOT MIN_LOGGED
create temp table in activated SP; while true { fetch 1000 messages; foreach message {insert into temp table results from processing SP} insert into live table from temp table; truncate temp table;}. That is, you needn't create one temp table for each call to your processing SP or even one per fetch from the queue; create it once and fill/empty it as necessary. But if you want to wait on MS, that's fine too.