Sunday, December 11, 2016

Retrieve Recent SQL Server Stats Update History with Trace Flag 2388

Ever had a "now you see it, now you don't" performance problem that you suspected was due to stats updates, but had a really hard time narrowing down?  Since auto-update stats is in such wide use, and even with auto updates most are using periodic manual stats updates as well, it can be hard to line up stats updates with plan selection changes.  Sometimes just a little more history of stats updates could be just enough to put you on the right path.  If that small bit of extra info would really help you out I've got good news!!

First thing needed is to find out which stats you need to be concerned about for a given query.
This blog post from Paul White (@SQL_Kiwi) shows how to use trace flags 9292 and 9204 to determine that.
http://sqlblog.com/blogs/paul_white/archive/2011/09/21/how-to-find-the-statistics-used-to-compile-an-execution-plan.aspx

Alternatively, trace flag 8666 can be used to retrieve info from the plan xml in the plan cache - or to make sure it gets put into Query Store.  Fabiano Neves Amorim (@mcflyamorim) describes that here.
https://blogfabiano.com/2012/07/03/statistics-used-in-a-cached-query-plan/ 

Using DBCC SHOW_STATISTICS or sys.dm_db_stats_properties the most recent stats update time can be retrieved.  But what about stats updates prior to that?

Most often, trace flag 2388 is thought of in connection with the "ascending key problem".  After enabling trace flag 2388 at the session level, DBCC SHOW_STATISTICS will inform for an index whether the "Leading column Type" has been branded as "Ascending, "Static", or "Unknown".  Trace flags 2389 & 2390 (with the legacy Cardinality Estimater) will cause cardinality estimates to take the lead column brand into account when the search area is beyond the highest RANGE_HI_KEY of the stats histogram. 

But as we see below the current brand of the "Leading column type" isn't the only interesting information in the SHOW_STATISTICS display under the influence of trace flag 2388.  There's also up to 3 times for updates previous to the most recent, for a total of four.

Here's a little test to show the way this information is retained as statistics are updated The WAITFOR DELAY is included only to differentiate the times - feel free to omit when trying for yourself at home :-). 

IF object_id('test2388') IS NOT NULL DROP TABLE test2388;
CREATE TABLE test2388(bigint_1 BIGINT);
CREATE NONCLUSTERED INDEX nci_bigint ON test2388(bigint_1);
DECLARE @INT INT = 1;
DBCC TRACEON(2388);
WHILE @INT < 14
    BEGIN
        INSERT INTO test2388 SELECT @INT;
        IF @INT IN (3, 7, 9, 11, 13)
             BEGIN
                  UPDATE STATISTICS test2388(nci_bigint);
                  DBCC SHOW_STATISTICS(test2388, nci_bigint);
                  WAITFOR DELAY '00:01';
             END
        SET @INT = @INT + 1;
    END
DBCC TRACEOFF(2388);







OK... now we know recent manual stats update history is displayed in SHOW_STATISTICS under the influence of trace flag 2388.  What about auto stats updates? Yep, they'll be in there too.  Here's a little test to demonstrate.

IF object_id('test2388') IS NOT NULL DROP TABLE test2388;
CREATE TABLE test2388(bigint_1 BIGINT);
CREATE NONCLUSTERED INDEX nci_bigint ON test2388(bigint_1);
DECLARE @INT INT = 1;
DBCC TRACEON(2388);
WHILE @INT < 4501
    BEGIN
        INSERT INTO test2388 SELECT @INT;
        IF @INT IN (1200, 2000, 3000, 4500)
             BEGIN
                  SELECT bigint_1 INTO #res FROM test2388 WHERE bigint_1 > 4;
                  DBCC SHOW_STATISTICS(test2388, nci_bigint);
                  DROP TABLE #res;
             END
        SET @INT = @INT + 1;
    END
DBCC TRACEOFF(2388);




One last thing I'll mention: I've seen a case where someone enabled trace flag 2388 globally for the SQL Server instance.  Nothing horrible happened, but it did throw some folks for a loop when they ran DBCC SHOW_STATISTICS and didn't see the output they expected :-)

I recommend using trace flag 2388 at session level only to prevent any consternation...

No comments:

Post a Comment