When CHECKDB Doesn’t Catch Corruption

Kevin Feasel

2017-07-20

DBCC

Paul Randal explains one condition when DBCC CHECKDB misses corruption:

An interesting situation was discussed online recently which prompted me to write this post. A fellow MVP was seeing periodic corruption messages in his error log, but DBCC CHECKDB on all databases didn’t find any corruptions. A subsequent restart of the instance caused the problem to go away.

My diagnosis? Memory corruption. Something had corrupted a page in memory – maybe it was bad memory chips or a memory scribbler (something that writes into SQL Server’s buffer pool, like a poorly-written extended stored procedure), or maybe a SQL Server bug. Whatever it was, restarting the instance wiped the buffer pool clean, removing the corrupt page.

So why didn’t DBCC CHECKDB encounter the corrupt page?

Read on for the rest of the story.

Finding Last DBCC Command Runs

Andrew Kelly has a script to find the last time somebody ran a DBCC command like DBCC FREEPROCCACHE:

Let me explain a few things about the script. I am getting the path of the current trace file and placing it into a variable. The current file name will almost certainly have a suffix of _nn just before the .trc extension.  If I were to run the script as is I would only be reading the current log file and not the other 4 that preceded it. If all you care about is the current log file then fine but most will want to search all the existing log files. One way to do this is to simply replace the current file name with just log.trc and use default as the 2nd parameter as I did above in the fn_trace_gettable function. The default parameter value tells the function to read all files from that one onward. even though log.trc doesn’t actually exist it knows how to handle it and reads all of the existing trace files in order.

So if the string that we search on (here we use ‘dbcc free%’) is in any of the files it will return the matching rows. You may have to adjust the wildcards and such but I think you get the idea. Again remember that the data is transient so always look at the StartTime column in the logs to ensure you know which Date and Time range you are looking at. You can do something like this but I will leave that up to you.

SELECT MIN(StartTime) AS [Begin], MAX(StartTime) AS [End]  FROM ::fn_trace_gettable(@Path,default)

A word of caution in that I never bothered to see just how resource intensive this function is. while I don’t expect any issues with normal use it is not something you want to be searching on every second. Be sensible and you should have no problems.

Click through for more details, including the script Andy uses to do this search.

Duplicate Key Error On DBCC CLONEDATABASE

Kevin Feasel

2017-06-15

Bugs, DBCC

Erin Stellato shows an edge case when you have a rather old database you’re trying to clone:

If you’ve been using DBCC CLONEDATABASE at all, you might have run into a cannot insert duplicate key error (or something similar) when trying to clone a database:

Database cloning for ‘YourDatabase’ has started with target as ‘COPY_YourDatabase’.
Msg 2601, Level 14, State 1, Line 1
Cannot insert duplicate key row in object ‘sys.sysschobjs’ with unique index ‘clst’. The duplicate key value is (1977058079).

If you do some searching, you’ll probably end up at this Connect item: DBCC DATABASECLONE fails on sys.sysowners.

The Connect item states that the problem exists because of user objects in model.  That’s not the case here.

I’m working with a database created in SQL Server 2000…now running on SQL Server 2016.

This isn’t very likely to pop up for most places (I hope!), but it’s good to know.

Incorrect PFS Free Space

Dave Mason walks through troubleshooting one database corruption scenario:

I’ve been lucky with database corruption during my career. I could probably count on one hand the number of times I’ve had to deal with it. A couple times, it was in a customer’s environment–they managed it themselves, but called me in to help. The other incidents were ones I inherited from a backup I had to restore into a production environment. The first time it happened to me, I didn’t realize it until days later when DBCC CHECKDB ran during a weekend maintenance window. After that, I added a new “rule” to my list: always run DBCC CHECKDB after restoring a database from someone else. That rule paid dividends today.

Here’s the output I saw:

Msg 8914, Level 16, State 1, Line 50
Incorrect PFS free space information for page (1:2564368) in object ID 457768688, index ID 1, partition ID 72057619124060160, alloc unit ID 72057594116767744 (type LOB data). Expected value 0_PCT_FULL, actual value 100_PCT_FULL.
CHECKDB found 0 allocation errors and 1 consistency errors in table 'tbl_Redacted' (object ID 457768688).
CHECKDB found 0 allocation errors and 1 consistency errors in database 'db_redacted'.
repair_allow_data_loss is the minimum repair level for the errors found by DBCC CHECKDB (db_redacted).

Read on to see how Dave solved this issue.

OLEDB Waits In CHECKTABLE

Lonny Niederstadt has dropped a boatload of information on us, with a four-part series looking at the OLEDB wait type when running DBCC CHECKTABLE.  Part 1 sets up the problem:

So… yeah.  Definitely a relationship between the number of pages in the heap and the number of OLEDB waits.  Something(s) increase the number of OLEDB waits beyond the number of data pages, the number of used pages and the number of reserved pages in a way that I haven’t deciphered yet, though.

Part 2 looks at what happens when logical checks run and not just physical checks:

On this very simple heap, with nearly the same number of rows as pages in the heap, the number of OLEDB wait events is nearly the same – only increased by one – when “upgrading” the checktable operation from physical_only to a checktable with logical checks.

Part 3 switches to using a clustered index, and things start getting wacky:

So how do the results match with expectations?  Whoa!!  25745 OLEDB wait events as the starting point for MAXDOP 1 and 2.  Then single-stepping up to 25752 OLEDB wait events for MAXDOP 8.  25752 is exactly 4 times the used page count of 6438 for the clustered index.  So the OLEDB wait events went from a small number more than the count of pages/rows with the heap… to almost 4 times as many with the clustered index.  *That* was a bit unexpected.

Part 4 looks at a heap with a non-clustered index:

All right.  What if we use a heap with a nonclustered include index?  Based on the table and index definition below, I expect the nonclustered include index nci_OLEDB_TEST_HEAP_NCI_INCLUDE to be remarkably similar to the clustered index we previously used.

Interesting reading so far in this series.

Scaling CheckTable With Respect To CPUs

Kevin Feasel

2017-05-31

DBCC

Lonny Niederstadt has a couple of posts on scaling DBCC CHECKTABLE based on degree of parallelism.  First, he looks at running the command with physical_only:

So we can use this formula when dop, elapsed_ms, and cpu_ms are known:

DOP * elapsed_ms = cpu_ms + idle_ms

That allows the 8 checktable operations to be summarized in this graph.  From DOP1 to DOP 8 the cpu_ms of the operation is extremely steady.  From DOP 1 to DOP 4 there are significant decreases in elapsed time as dop increases.  After dop 4, reduction in elapsed time is slight.  Throughout the tested range, idle_ms increased at a nearly linear rate.

In his second post, he looks at full CHECKTABLE runs and not just physical_only:

So the good news for today is that checktable operations without the physical_only option scale farther/better on my test tables than checktable with physical_only.  While with physical_only scaling benefits in elapsed time are primarily seen only to dop 4, without the physical_only option elapsed time benefits to increasing dop extend at least to dop 8.
And we saw that the shape of scalability graphs is pretty volatile 🙂  That’s largely because modest changes in elapsed time are multiplied by dop in this calculation to arrive at the idle_ms number – that idle_ms number is the one that changes shape most readily.

These are prologue posts to a discussion on the OLEDB wait type.

Doubly Linked Lists And Bugs

Ewald Cress explains a bug in DBCC PAGE:

Let’s start with the safety convention. The “null” of a null pointer isn’t a magic value, but in real-life implementation is simply zero, which is a perfectly valid virtual address. However, on the premise that trying to access address zero or addresses near it probably indicates a program error, the OS will map that page in such a way that trying to access it causes an access violation. This is not a bug or an accident, but a damn clever feature! Robert Love explains it very nicely over here for Linux, and it applies equally to Windows.

Now recall the convention that trying to retrieve the head or tail of an empty list will – by convention – bring you back a null pointer. When iterating, a related convention may also return a zero when you’ve gone all the way around and come back to the list head. Clearly the onus is on the developer to recognise that null pointer and not dereference it, but attempting to do so sets in motion the safety feature of an access violation, which can then be neatly caught through standard exception handling, for instance yielding a diagnostic stack dump.

Very interesting article, and also a good juxtaposition of supported, “production-safe” code versus undocumented processes.

Last Known Good DBCC CHECKDB In Powershell

Rob Sewell shows off a cmdlet to check DBCC DBINFO for each database to get the last known good CHECKDB run:

This time we get more information. The server name, database name, when the database was created, the last good DBCC Checkdb, how long since the database was created, how long since the last known good DBCC Checkdb, a status and a Data Purity enabled flag. If you look at the image above it shows that the DBA_Admin database has a status of “New database, not checked yet” even though it has a date for the last known good DBCC CheckDb. This is because it was restored after this server was upgrade from CTP 1.3 to CTP 1.4 and there has not yet been a DBCC CheckDb run yet. The system databases have a status of “CheckDb should be performed”. This is because the last known good DBCC CheckDb is more than 7 days ago. Lets run a DBCC CheckDb and check again

Do read the caveats, and also check out a previous Arun Sirpal blog post on DBCC DBINFO.

Columnstore Indexes On Cloned Databases

Parikshit Savjani has a script to update columnstore index statistics before running DBCC CLONEDATABASE:

Unlike traditional Btree indexes, when a columnstore index is created, there is no index statistics created on the columns of the columnstore indexes. However, there is an empty stats object created with the same name as columnstore index and an entry is added to sys.stats at the time of index creation. The stats object is populated on the fly when a query is executed against the columnstore index or when executing DBCC SHOW_STATISTICS against the columnstore index, but the columnstore index statistics aren’t persisted in the storage. The index statistics is different from the auto created statistics on the individual columns of columnstore indexes which is generated on the fly and persisted in the statistics object. Since the index statistics is
not persisted in storage, the clonedatabase will not contain those statistics leading to inaccurate stats and different query plans when same query has run against database clone as opposed to production database.

Click through for the script.

Understanding DBCC OPENTRAN

Kevin Feasel

2017-04-04

DBCC

Kevin Hill goes into detail on what DBCC OPENTRAN does:

I have verified that new records I inserted have been read by the log reader, AND distributed to the subscriber(s).  This means that while you are seeing

Oldest distributed LSN : (37:157:3)

There is not an error…just info.

If you have non-distributed LSNs, there is something to troubleshoot in the replication process which is way outside the scope of this post.  A non-distributed replicated transaction/LSN CAN cause some huge Log file growth, and need to be investigated.  If this happens frequently, use the TABLERESULTS option to log to a regular table and alert on it.

Good information here.

Categories

August 2017
MTWTFSS
« Jul  
 123456
78910111213
14151617181920
21222324252627
28293031