Benjamin Nevarez Rotating Header Image

Trace Flags

Statistics on Ascending Keys

One query processor problem I’ve been trying to research since some time ago is that of statistics on ascending keys. The traditional recommendation from Microsoft to fix this problem is to manually update statistics after loading data as explained here. The document describes the problem in the following way:

“Statistics on ascending or descending key columns, such as IDENTITY or real-time timestamp columns, might require more frequent statistics updates than the query optimizer performs. Insert operations append new values to ascending or descending columns. The number of rows added might be too small to trigger a statistics update. If statistics are not up-to-date and queries select from the most recently added rows, the current statistics will not have cardinality estimates for these new values. This can result in inaccurate cardinality estimates and slow query performance. For example, a query that selects from the most recent sales order dates will have inaccurate cardinality estimates if the statistics are not updated to include cardinality estimates for the most recent sales order dates.”

Trace flags 2389 and 2390, which were first published by Ian Jose in his article Ascending Keys and Auto Quick Corrected Statistics, can help to address this problem. Ian explains that when data typically ascends, most new insertions are out of the previously found range. My testing shows that these new values fall outside the range of values of the existing statistics histogram. This can lead to poorly performing plans as filters selecting recent data seem to exclude the entire relation when in fact a significant number of rows may be included.

To show you what the problem is and how this mystery trace flags 2389 works, let us start by creating a table in AdventureWorks2012.

CREATE TABLE dbo.SalesOrderHeader (
    SalesOrderID int NOT NULL,
    RevisionNumber tinyint NOT NULL,
    OrderDate datetime NOT NULL,
    DueDate datetime NOT NULL,
    ShipDate datetime NULL,
    Status tinyint NOT NULL,
    OnlineOrderFlag dbo.Flag NOT NULL,
    SalesOrderNumber nvarchar(25) NOT NULL,
    PurchaseOrderNumber dbo.OrderNumber NULL,
    AccountNumber dbo.AccountNumber NULL,
    CustomerID int NOT NULL,
    SalesPersonID int NULL,
    TerritoryID int NULL,
    BillToAddressID int NOT NULL,
    ShipToAddressID int NOT NULL,
    ShipMethodID int NOT NULL,
    CreditCardID int NULL,
    CreditCardApprovalCode varchar(15) NULL,
    CurrencyRateID int NULL,
    SubTotal money NOT NULL,
    TaxAmt money NOT NULL,
    Freight money NOT NULL,
    TotalDue money NOT NULL,
    Comment nvarchar(128) NULL,
    rowguid uniqueidentifier NOT NULL,
    ModifiedDate datetime NOT NULL
)

Populate the table with some initial data and create an index on it (notice that both tables have the same name but in the dbo and Sales schemas)

INSERT INTO dbo.SalesOrderHeader SELECT * FROM Sales.SalesOrderHeader 
WHERE OrderDate < '2008-07-20 00:00:00.000'
CREATE INDEX IX_OrderDate ON SalesOrderHeader(OrderDate)

The problem

After creating the index SQL Server will also create a statistics object for it, so a query like this will have a good cardinality estimate as shown next (as there is data for July 19 and it is captured on the last step of the statistics histogram object, which you can verify by using the DBCC SHOW_STASTISTICS statement).

SELECT * FROM dbo.SalesOrderHeader WHERE OrderDate = '2008-07-19 00:00:00.000'

clip_image001

Now, let us suppose we add new data for July 20th.

INSERT INTO dbo.SalesOrderHeader SELECT * FROM Sales.SalesOrderHeader 
WHERE OrderDate = '2008-07-20 00:00:00.000'

Changing the query to look for records for July 20

SELECT * FROM dbo.SalesOrderHeader WHERE OrderDate = '2008-07-20 00:00:00.000'

Since the number of rows added is too small, it does not trigger an automatic update of statistics. And since the value July 20 is not represented on the histogram SQL Server will use an estimate of 1 as shown in the following plan

clip_image002

Although both plans showed in this example are very similar a bad cardinality estimate may produce bad plans in some more realistic scenarios and queries.

Using trace flag 2389

Now let us see how trace flag 2389 helps on this problem. Run the next statements (notice that trace flag 2388 has not been mentioned before and will be explained shortly)

DBCC TRACEON (2388)
DBCC TRACEON (2389)

Trace flag 2389, which was introduced with SQL Server 2005 Service Pack 1, begins to track the nature of columns via subsequent operations of updating statistics. When the statistics are seen to increase three times in a row the column is branded ascending.

Trace flag 2388 is not required to enable the behavior described in this article but we can use it to show how trace flags 2390 works and determine if a column has been branded ascending. The trace flag changes the output of the DBCC SHOW_STATISTICS statement to show you a historical look at the most recent statistics update operations.

Trace flag 2390 enables a similar behavior than 2389 even if the ascending nature of the column is not known but I will not cover it here.

Run DBCC SHOW_STASTISTICS

DBCC SHOW_STATISTICS ('dbo.SalesOrderHeader', 'IX_OrderDate')

The statement shows the following output

Updated              Table Cardinality      Snapshot Ctr         Steps  Density                Rows Above             Rows Below             Squared Variance Error Inserts Since Last Update Deletes Since Last Update Leading column Type
-------------------- ---------------------- -------------------- ------ ---------------------- ---------------------- ---------------------- ---------------------- ------------------------- ------------------------- -------------------
Feb 26 2013  2:31AM  31095                  31095                199    0.000899280596058816   NULL                   NULL                   NULL                   NULL                      NULL                      Unknown

Not much data for now. But I’ll show you this output after three consecutive batches inserting data and updating statistics. Run the following statement to update statistics including the data you just added for February 20th.

UPDATE STATISTICS dbo.SalesOrderHeader WITH FULLSCAN

DBCC SHOW_STATISTICS now shows

Updated              Table Cardinality      Snapshot Ctr         Steps  Density                Rows Above             Rows Below             Squared Variance Error Inserts Since Last Update Deletes Since Last Update Leading column Type
-------------------- ---------------------- -------------------- ------ ---------------------- ---------------------- ---------------------- ---------------------- ------------------------- ------------------------- -------------------
Feb 26 2013  2:40AM  31125                  31125                199    0.000898472615517676   30                     0                      0.0135968539563045     30                        0                         Unknown
Feb 26 2013  2:31AM  31095                  31095                199    0.000899280596058816   NULL                   NULL                   NULL                   NULL                      NULL                      NULL

where ‘Rows Above’ and ‘Insert Since Last Update’ accounts for the 30 rows added previously (you may need to scroll to the right). Now run the second batch

INSERT INTO dbo.SalesOrderHeader SELECT * FROM Sales.SalesOrderHeader 
WHERE OrderDate = '2008-07-21 00:00:00.000'

Again running this query will verify the one row estimate in the plan

SELECT * FROM dbo.SalesOrderHeader WHERE OrderDate = '2008-07-21 00:00:00.000'

Update statistics again

UPDATE STATISTICS dbo.SalesOrderHeader WITH FULLSCAN

DBCC SHOW_STATISTICS now shows this. Notice a new record with ‘Insert Since Last Update’ and ‘Rows Above’ with a value of 27. ‘Leading column Type’ still shows ‘Unknown’.

Updated              Table Cardinality      Snapshot Ctr         Steps  Density                Rows Above             Rows Below             Squared Variance Error Inserts Since Last Update Deletes Since Last Update Leading column Type
-------------------- ---------------------- -------------------- ------ ---------------------- ---------------------- ---------------------- ---------------------- ------------------------- ------------------------- -------------------
Feb 26 2013  2:44AM  31152                  31152                199    0.000897666090168059   27                     0                      0.0122265623860741     27                        0                         Unknown
Feb 26 2013  2:40AM  31125                  31125                199    0.000898472615517676   30                     0                      0.0135968539563045     30                        0                         NULL
Feb 26 2013  2:31AM  31095                  31095                199    0.000899280596058816   NULL                   NULL                   NULL                   NULL                      NULL                      NULL

A third batch

INSERT INTO dbo.SalesOrderHeader SELECT * FROM Sales.SalesOrderHeader 
WHERE OrderDate = '2008-07-22 00:00:00.000'

Update statistics one last time

UPDATE STATISTICS dbo.SalesOrderHeader WITH FULLSCAN

DBCC SHOW_STATISTICS now shows

Updated              Table Cardinality      Snapshot Ctr         Steps  Density                Rows Above             Rows Below             Squared Variance Error Inserts Since Last Update Deletes Since Last Update Leading column Type
-------------------- ---------------------- -------------------- ------ ---------------------- ---------------------- ---------------------- ---------------------- ------------------------- ------------------------- -------------------
Feb 26 2013  2:47AM  31184                  31184                199    0.000896860961802304   32                     0                      0.0144758706820584     32                        0                         Ascending
Feb 26 2013  2:44AM  31152                  31152                199    0.000897666090168059   27                     0                      0.0122265623860741     27                        0                         NULL
Feb 26 2013  2:40AM  31125                  31125                199    0.000898472615517676   30                     0                      0.0135968539563045     30                        0                         NULL
Feb 26 2013  2:31AM  31095                  31095                199    0.000899280596058816   NULL                   NULL                   NULL                   NULL                      NULL                      NULL

In addition to the new record accounting for the 32 rows added, now you can notice that the branding was changed to ‘Ascending’. Once the column is branded ‘Ascending’ SQL Server will be able to give you a better cardinality estimate, without the need to manually update statistics.

Now try this batch

INSERT INTO dbo.SalesOrderHeader SELECT * FROM Sales.SalesOrderHeader 
WHERE OrderDate = '2008-07-23 00:00:00.000'

And run the following query

SELECT * FROM dbo.SalesOrderHeader WHERE OrderDate = '2008-07-23 00:00:00.000'

This time we get a better cardinality estimate. Notice that no UPDATE STATISTICS was required this time.

clip_image011

Instead the estimated of one row now we get 27.9677. But where is this value coming from? The query optimizer is now using the density information of the statistics object. The definition of density is 1 / number of distinct values and the estimated number of rows is obtained using the density multiplied by the number of records in the table which in this case is 0.000896861 * 31184, or 27.967713424 as shown in the plan. Also notice that density information is only used for values not covered in the histogram (You can see the density information using the same DBCC SHOW_STATISTICS statement but in another session where trace flag 2388 is not enabled).

In addition, if we look for data that does not exist we still get the one row estimate which is always adequate since it will return 0 records.

SELECT * FROM dbo.SalesOrderHeader WHERE OrderDate = '2008-07-23 00:00:00.000'

Notice that branding a column ascending requires statistics to increase three times in a row. If later we insert older data, breaking the ascending sequence, the column ‘Leading column Type’ will show ‘Stationary’ and the query processor will be back to the original cardinality estimate behavior. Three new additional updates in a row with increasing values can brand it as Ascending again.

Finally, at this moment I am not able to verify if these trace flags are “officially” documented and supported by Microsoft. Interestingly they are documented in the article FIX: You may notice a large increase in compile time when you enable trace flags 2389 and 2390 in SQL Server 2005 Service Pack 1 (look at the ‘More Information’ section). Another fix is documented here. Anyway, in any case talk to Microsoft and obviously test your application carefully if you think that these trace flags can improve the performance of your application.

More Undocumented Query Optimizer Trace Flags

 

clip_image001

This is my second post discussing some query optimizer undocumented trace flags (you can read the first one, “Inside the Query Optimizer Memo Structure”, here). Although is not the purpose of this post to discuss the entire optimization process or go into detail on any of the optimization phases, you can read more about it in my book Inside the SQL Server Query Optimizer, which you can download for free from the simple-talk website. And same as before, please bear in mind that all these trace flags are undocumented and unsupported, and should not be used on a production environment. You can use them as a way to explore and understand how the query optimizer works.

As mentioned in my previous post, you will first have to enable the trace flag 3604 to redirect the trace output to the client executing the command, in this case to the Messages tab in SQL Server Management Studio.

DBCC TRACEON(3604)

I’ll start with three trace flags which display logical and physical trees used during the optimization process. First, trace flag 8605 will display the query initial tree representation created by SQL Server. Test if by running

SELECT e.EmployeeID FROM HumanResources.Employee AS e
INNER JOIN Sales.SalesPerson AS s ON e.EmployeeID = s.SalesPersonID
OPTION (RECOMPILE, QUERYTRACEON 8605)

It will show the following output

*** Converted Tree: ***
    LogOp_Project QCOL: [e].EmployeeID
        LogOp_Join
            LogOp_Get TBL: HumanResources.Employee(alias TBL: e) HumanResources.Employee TableID=901578250 TableReferenceID=0 IsRow: COL: IsBaseRow1001 
            LogOp_Get TBL: Sales.SalesPerson(alias TBL: s) Sales.SalesPerson TableID=1042102753 TableReferenceID=0 IsRow: COL: IsBaseRow1003 
            ScaOp_Comp x_cmpEq
                ScaOp_Identifier QCOL: [e].EmployeeID
                ScaOp_Identifier QCOL: [s].SalesPersonID
        AncOp_PrjList 

Trace flag 8606 will display additional logical trees used during the optimization process. Run

SELECT e.EmployeeID FROM HumanResources.Employee AS e
INNER JOIN Sales.SalesPerson AS s ON e.EmployeeID = s.SalesPersonID
OPTION (RECOMPILE, QUERYTRACEON 8606)

The output shows several different logical trees: input tree, simplified tree, join-collapsed tree, tree before project normalization, and tree after project normalization. These trees will include logical operators only. Part of the output is shown next.

*** Input Tree: *** LogOp_Project QCOL: [e].EmployeeID LogOp_Select LogOp_Join LogOp_Get TBL: HumanResources.Employee(alias TBL: e) HumanResources.Employee TableID=901578250 TableReferenceID=0 IsRow: COL: IsBaseRow1001 LogOp_Get TBL: Sales.SalesPerson(alias TBL: s) Sales.SalesPerson TableID=1042102753 TableReferenceID=0 IsRow: COL: IsBaseRow1003 ScaOp_Const TI(bit,ML=1) XVAR(bit,Not Owned,Value=1) ScaOp_Comp x_cmpEq ScaOp_Identifier QCOL: [e].EmployeeID ScaOp_Identifier QCOL: [s].SalesPersonID AncOp_PrjList *******************

*** Simplified Tree: *** LogOp_Join LogOp_Get TBL: HumanResources.Employee(alias TBL: e) HumanResources.Employee TableID=901578250 TableReferenceID=0 IsRow: COL: IsBaseRow1001 LogOp_Get TBL: Sales.SalesPerson(alias TBL: s) Sales.SalesPerson TableID=1042102753 TableReferenceID=0 IsRow: COL: IsBaseRow1003 ScaOp_Comp x_cmpEq ScaOp_Identifier QCOL: [s].SalesPersonID ScaOp_Identifier QCOL: [e].EmployeeID ******************* *** Join-collapsed Tree: *** LogOp_Join LogOp_Get TBL: HumanResources.Employee(alias TBL: e) HumanResources.Employee TableID=901578250 TableReferenceID=0 IsRow: COL: IsBaseRow1001 LogOp_Get TBL: Sales.SalesPerson(alias TBL: s) Sales.SalesPerson TableID=1042102753 TableReferenceID=0 IsRow: COL: IsBaseRow1003 ScaOp_Comp x_cmpEq ScaOp_Identifier QCOL: [s].SalesPersonID ScaOp_Identifier QCOL: [e].EmployeeID ******************* *** Tree Before Project Normalization *** LogOp_Join LogOp_Get TBL: HumanResources.Employee(alias TBL: e) HumanResources.Employee TableID=901578250 TableReferenceID=0 IsRow: COL: IsBaseRow1001 LogOp_Get TBL: Sales.SalesPerson(alias TBL: s) Sales.SalesPerson TableID=1042102753 TableReferenceID=0 IsRow: COL: IsBaseRow1003 ScaOp_Comp x_cmpEq ScaOp_Identifier QCOL: [s].SalesPersonID ScaOp_Identifier QCOL: [e].EmployeeID ***************************************** *** Tree After Project Normalization *** LogOp_Join LogOp_Get TBL: HumanResources.Employee(alias TBL: e) HumanResources.Employee TableID=901578250 TableReferenceID=0 IsRow: COL: IsBaseRow1001 LogOp_Get TBL: Sales.SalesPerson(alias TBL: s) Sales.SalesPerson TableID=1042102753 TableReferenceID=0 IsRow: COL: IsBaseRow1003 ScaOp_Comp x_cmpEq ScaOp_Identifier QCOL: [s].SalesPersonID ScaOp_Identifier QCOL: [e].EmployeeID **************************************** *** Stop search, level 1 ***

One interesting example is seeing how a tree is simplified when the query optimizer can detect a contradiction during the simplification phase. The purpose of the simplification stage is to reduce the query tree into a simpler form in order to make the optimization process easier. Contradiction detection is one of several possible simplifications. Following on an example on my book and this blog post, run the following query

SELECT * FROM HumanResources.Employee
WHERE VacationHours > 300
OPTION (RECOMPILE, QUERYTRACEON 8606)

Part of the output is next

*** Input Tree: ***
        LogOp_Project QCOL: [AdventureWorks].[HumanResources].[Employee].EmployeeID QCOL: [AdventureWorks].[HumanResources].[Employee].NationalIDNumber QCOL: [AdventureWorks].[HumanResources].[Employee].ContactID QCOL: [AdventureWorks].[HumanResources].[Employee].LoginID QCOL: [AdventureWorks].[HumanResources].[Employee].ManagerID QCOL: [AdventureWorks].[HumanResources].[Employee].Title QCOL: [AdventureWorks].[HumanResources].[Employee].BirthDate QCOL: [AdventureWorks].[HumanResources].[Employee].MaritalStatus QCOL: [AdventureWorks].[HumanResources].[Employee].Gender QCOL: [AdventureWorks].[HumanResources].[Employee].HireDate QCOL: [AdventureWorks].[HumanResources].[Employee].SalariedFlag QCOL: [AdventureWorks].[HumanResources].[Employee].VacationHours QCOL: [AdventureWorks].[HumanResources].[Employee].SickLeaveHours QCOL: [AdventureWorks].[HumanResources].[Employee].CurrentFlag QCOL: [AdventureWorks].[HumanResources].[Employee].rowguid QCOL: [AdventureWorks].[HumanResources].[Employee].ModifiedDate
            LogOp_Select
                LogOp_Get TBL: HumanResources.Employee HumanResources.Employee TableID=901578250 TableReferenceID=0 IsRow: COL: IsBaseRow1001 
                ScaOp_Comp x_cmpGt
                    ScaOp_Identifier QCOL: [AdventureWorks].[HumanResources].[Employee].VacationHours
                    ScaOp_Const TI(smallint,ML=2) XVAR(smallint,Not Owned,Value=300)
            AncOp_PrjList 
*******************
*** Simplified Tree: ***
        LogOp_ConstTableGet (0) COL: Chk1000  COL: IsBaseRow1001  QCOL: [AdventureWorks].[HumanResources].[Employee].EmployeeID QCOL: [AdventureWorks].[HumanResources].[Employee].NationalIDNumber QCOL: [AdventureWorks].[HumanResources].[Employee].ContactID QCOL: [AdventureWorks].[HumanResources].[Employee].LoginID QCOL: [AdventureWorks].[HumanResources].[Employee].ManagerID QCOL: [AdventureWorks].[HumanResources].[Employee].Title QCOL: [AdventureWorks].[HumanResources].[Employee].BirthDate QCOL: [AdventureWorks].[HumanResources].[Employee].MaritalStatus QCOL: [AdventureWorks].[HumanResources].[Employee].Gender QCOL: [AdventureWorks].[HumanResources].[Employee].HireDate QCOL: [AdventureWorks].[HumanResources].[Employee].SalariedFlag QCOL: [AdventureWorks].[HumanResources].[Employee].VacationHours QCOL: [AdventureWorks].[HumanResources].[Employee].SickLeaveHours QCOL: [AdventureWorks].[HumanResources].[Employee].CurrentFlag QCOL: [AdventureWorks].[HumanResources].[Employee].rowguid QCOL: [AdventureWorks].[HumanResources].[Employee].ModifiedDate
*******************
*** Join-collapsed Tree: ***
        LogOp_ConstTableGet (0) COL: Chk1000  COL: IsBaseRow1001  QCOL: [AdventureWorks].[HumanResources].[Employee].EmployeeID QCOL: [AdventureWorks].[HumanResources].[Employee].NationalIDNumber QCOL: [AdventureWorks].[HumanResources].[Employee].ContactID QCOL: [AdventureWorks].[HumanResources].[Employee].LoginID QCOL: [AdventureWorks].[HumanResources].[Employee].ManagerID QCOL: [AdventureWorks].[HumanResources].[Employee].Title QCOL: [AdventureWorks].[HumanResources].[Employee].BirthDate QCOL: [AdventureWorks].[HumanResources].[Employee].MaritalStatus QCOL: [AdventureWorks].[HumanResources].[Employee].Gender QCOL: [AdventureWorks].[HumanResources].[Employee].HireDate QCOL: [AdventureWorks].[HumanResources].[Employee].SalariedFlag QCOL: [AdventureWorks].[HumanResources].[Employee].VacationHours QCOL: [AdventureWorks].[HumanResources].[Employee].SickLeaveHours QCOL: [AdventureWorks].[HumanResources].[Employee].CurrentFlag QCOL: [AdventureWorks].[HumanResources].[Employee].rowguid QCOL: [AdventureWorks].[HumanResources].[Employee].ModifiedDate
*******************
*** Tree Before Project Normalization ***
        LogOp_ConstTableGet (0) COL: Chk1000  COL: IsBaseRow1001  QCOL: [AdventureWorks].[HumanResources].[Employee].EmployeeID QCOL: [AdventureWorks].[HumanResources].[Employee].NationalIDNumber QCOL: [AdventureWorks].[HumanResources].[Employee].ContactID QCOL: [AdventureWorks].[HumanResources].[Employee].LoginID QCOL: [AdventureWorks].[HumanResources].[Employee].ManagerID QCOL: [AdventureWorks].[HumanResources].[Employee].Title QCOL: [AdventureWorks].[HumanResources].[Employee].BirthDate QCOL: [AdventureWorks].[HumanResources].[Employee].MaritalStatus QCOL: [AdventureWorks].[HumanResources].[Employee].Gender QCOL: [AdventureWorks].[HumanResources].[Employee].HireDate QCOL: [AdventureWorks].[HumanResources].[Employee].SalariedFlag QCOL: [AdventureWorks].[HumanResources].[Employee].VacationHours QCOL: [AdventureWorks].[HumanResources].[Employee].SickLeaveHours QCOL: [AdventureWorks].[HumanResources].[Employee].CurrentFlag QCOL: [AdventureWorks].[HumanResources].[Employee].rowguid QCOL: [AdventureWorks].[HumanResources].[Employee].ModifiedDate
*****************************************
*** Tree After Project Normalization ***
        LogOp_ConstTableGet (0) COL: Chk1000  COL: IsBaseRow1001  QCOL: [AdventureWorks].[HumanResources].[Employee].EmployeeID QCOL: [AdventureWorks].[HumanResources].[Employee].NationalIDNumber QCOL: [AdventureWorks].[HumanResources].[Employee].ContactID QCOL: [AdventureWorks].[HumanResources].[Employee].LoginID QCOL: [AdventureWorks].[HumanResources].[Employee].ManagerID QCOL: [AdventureWorks].[HumanResources].[Employee].Title QCOL: [AdventureWorks].[HumanResources].[Employee].BirthDate QCOL: [AdventureWorks].[HumanResources].[Employee].MaritalStatus QCOL: [AdventureWorks].[HumanResources].[Employee].Gender QCOL: [AdventureWorks].[HumanResources].[Employee].HireDate QCOL: [AdventureWorks].[HumanResources].[Employee].SalariedFlag QCOL: [AdventureWorks].[HumanResources].[Employee].VacationHours QCOL: [AdventureWorks].[HumanResources].[Employee].SickLeaveHours QCOL: [AdventureWorks].[HumanResources].[Employee].CurrentFlag QCOL: [AdventureWorks].[HumanResources].[Employee].rowguid QCOL: [AdventureWorks].[HumanResources].[Employee].ModifiedDate

In this case the query optimizer makes use of an existing check constraint to conclude that no records qualify for the predicate VacationHours > 300, replacing the entire tree with a LogOp_ConstTableGet logical operator. If you try displaying an output tree, as discussed next, you will get a PhyOp_ConstTableScan physical operator, and you will get a constant scan operator on the final execution plan. You can see a different behavior if you try the same query with a predicate like VacationHours > 20.

Trace flag 8607 shows the optimization output tree. Try the following sentence

SELECT e.EmployeeID FROM HumanResources.Employee AS e
INNER JOIN Sales.SalesPerson AS s ON e.EmployeeID = s.SalesPersonID
OPTION (RECOMPILE, QUERYTRACEON 8607)

Notice that this time we have physical operators and the output tree is closer to the final execution plan.

****************************************
*** Output Tree: ***
        PhyOp_Apply lookup TBL: HumanResources.Employee (0) (x_jtInner)
            PhyOp_Range TBL: Sales.SalesPerson(alias TBL: s)(2) ASC  Bmk ( QCOL: [s].SalesPersonID) IsRow: COL: IsBaseRow1003 
            PhyOp_Range TBL: HumanResources.Employee(alias TBL: e)(1) ASC  Bmk ( QCOL: [e].EmployeeID) IsRow: COL: IsBaseRow1001 
                ScaOp_Comp x_cmpEq
                    ScaOp_Identifier QCOL: [s].SalesPersonID
                    ScaOp_Identifier QCOL: [e].EmployeeID
********************
** Query marked as Cachable
********************

Trace flag 8675 shows the query optimization phases for a specific optimization along with some other information like cost estimation, tasks, etc. You may want to test it with complex queries to see different optimization phases like in the following example

SELECT I.CustomerID, C.FirstName, C.LastName, A.AddressLine1, A.City,
SP.Name AS State, CR.Name AS CountryRegion
FROM Person.Contact AS C
JOIN Sales.Individual AS I ON C.ContactID = I.ContactID
JOIN Sales.CustomerAddress AS CA ON CA.CustomerID = I.CustomerID
JOIN Person.Address AS A ON A.AddressID = CA.AddressID
JOIN Person.StateProvince SP ON
SP.StateProvinceID = A.StateProvinceID
JOIN Person.CountryRegion CR ON
CR.CountryRegionCode = SP.CountryRegionCode
ORDER BY I.CustomerID
OPTION (RECOMPILE, QUERYTRACEON 8675)

It shows the following output

End of simplification, time: 0.003 net: 0.003 total: 0.003 net: 0.003
end exploration, tasks: 275 no total cost time: 0.005 net: 0.005 total: 0.009 net: 0.009
end exploration, tasks: 642 no total cost time: 0.003 net: 0.003 total: 0.012 net: 0.012
end search(0),  cost: 9.04 tasks: 681 time: 0 net: 0 total: 0.013 net: 0.013
end exploration, tasks: 1465 Cost = 9.04 time: 0.004 net: 0.004 total: 0.017 net: 0.017
end exploration, tasks: 2518 Cost = 9.04 time: 0.007 net: 0.007 total: 0.024 net: 0.024
end search(1),  cost: 5.86879 tasks: 2609 time: 0 net: 0 total: 0.025 net: 0.025
end exploration, tasks: 2610 Cost = 5.86879 time: 0 net: 0 total: 0.025 net: 0.025
end exploration, tasks: 5170 Cost = 5.86879 time: 0.021 net: 0.021 total: 0.047 net: 0.047
end search(1),  cost: 5.86248 tasks: 5469 time: 0.001 net: 0.001 total: 0.048 net: 0.048
end exploration, tasks: 5756 Cost = 5.86248 time: 0.001 net: 0.001 total: 0.05 net: 0.05
end exploration, tasks: 6434 Cost = 5.86248 time: 0.005 net: 0.005 total: 0.055 net: 0.055
end search(2),  cost: 5.84575 tasks: 7092 time: 0.004 net: 0.004 total: 0.059 net: 0.059
End of post optimization rewrite, time: 0 net: 0 total: 0.059 net: 0.059
End of query plan compilation, time: 0 net: 0 total: 0.06 net: 0.06

Note the optimization phases search(0), search(1) and search(2). Also, as mentioned in my book, you need at least three tables to qualify for search 0, so the following query will go directly to search 1 (you can also test this with trace flag 2372 as described later):

SELECT * FROM HumanResources.Employee
WHERE ManagerID = 12
OPTION (RECOMPILE, QUERYTRACEON 8675)

Trace flags 2372 and 2373 show memory utilization during the optimization process but we can also use them to gain information about the activities the query optimizer is performing for a particular query. Trace flag 2372 shows memory utilization during the different optimization stages. Same as before, more complicated queries will show more optimization stages.

SELECT I.CustomerID, C.FirstName, C.LastName, A.AddressLine1, A.City,
SP.Name AS State, CR.Name AS CountryRegion
FROM Person.Contact AS C
JOIN Sales.Individual AS I ON C.ContactID = I.ContactID
JOIN Sales.CustomerAddress AS CA ON CA.CustomerID = I.CustomerID
JOIN Person.Address AS A ON A.AddressID = CA.AddressID
JOIN Person.StateProvince SP ON
SP.StateProvinceID = A.StateProvinceID
JOIN Person.CountryRegion CR ON
CR.CountryRegionCode = SP.CountryRegionCode
ORDER BY I.CustomerID
OPTION (RECOMPILE, QUERYTRACEON 2372)

The output is next

Memory before NNFConvert: 13
Memory after NNFConvert: 14
Memory before project removal: 15
Memory after project removal: 15
Memory before simplification: 15
Memory after simplification: 35
Memory before heuristic join reordering: 35
Memory after heuristic join reordering: 46
Memory before project normalization: 46
Memory after project normalization: 46
Memory before stage TP: 46
Memory after stage TP: 81
Memory before stage QuickPlan: 81
Memory after stage QuickPlan: 144
Memory before stage Full: 144
Memory after stage Full: 156
Memory before copy out: 156
Memory after copy out: 157

Notice that “stage TP” or transaction processing phase is the same as search(0) shown before with trace flag 8675. In the same way, “stage QuickPlan” is the search(1) and “stage Full” is search(2).

Trace flag 2373 shows memory utilization while applying optimization rules and deriving properties.

SELECT e.EmployeeID FROM HumanResources.Employee AS e
INNER JOIN Sales.SalesPerson AS s ON e.EmployeeID = s.SalesPersonID
OPTION (RECOMPILE, QUERYTRACEON 2373)

Part of the output is next

Memory before rule IJtoIJSEL: 14
Memory after rule IJtoIJSEL: 14
Memory before rule MatchGet: 14
Memory after rule MatchGet: 14
Memory before rule MatchGet: 14
Memory after rule MatchGet: 14
Memory before rule JoinToIndexOnTheFly: 14
Memory after rule JoinToIndexOnTheFly: 14
Memory before rule JoinCommute: 14
Memory after rule JoinCommute: 14
Memory before rule JoinToIndexOnTheFly: 14
Memory after rule JoinToIndexOnTheFly: 14
Memory before rule JNtoIdxLookup: 14

Finally, trace 8757 can be used to skip the trivial plan optimization and basically force a full optimization. As a reminder, the trivial plan optimization is used for very simple queries that don’t require any cost estimation decision. For example, the following query will produce a trivial plan, which you can verify by looking at the optimization level or StatementOptmLevel property in your execution plan

SELECT * FROM dbo.DatabaseLog

By applying trace flag 8757, the trivial plan optimization will be skipped as you can verify by running the following query and once again verifying the optimization level property.

SELECT * FROM dbo.DatabaseLog
OPTION (QUERYTRACEON 8757)

Inside the Query Optimizer Memo Structure

I just learned a few query-optimizer-related undocumented trace flags from my friend Dmitry Pilugin, who blogged about them in his blog in Russian, SomewhereSomehow’s Blog, and asked me if I could be interested in posting something in English. Some of these interesting trace flags allow us to see the contents of the memo structure, something I was trying to find while writing my book Inside the SQL Server Query Optimizer.

But first, a quick reminder of what the memo structure is. The memo is a search data structure that is used to store the alternatives generated and analyzed by the SQL Server query optimizer. These alternatives can be logical or physical operators and are organized into groups such that each alternative in the same group produces the same results. The query optimizer first copies the original query tree’s logical expressions into the memo structure, placing each operator from the query tree in its own group, and then triggers the entire optimization process. During this process, transformation rules are applied to generate all the alternatives, starting with these initial logical expressions. As the transformation rules produce new alternatives, these are added to their equivalent groups. Transformation rules may also produce a new expression which is not equivalent to any existing group, and which causes a new group to be created. A new memo structure is created for each optimization.

But instead of trying to explain the basics of how the memo structure works you can refer to my book, Inside the SQL Server Query Optimizer, which you can download for free from the simple-talk website. In this post I will show you how to see the contents of the memo structure. First enable the trace flag 3604 to redirect the trace output to the client executing the command, in this case SQL Server Management Studio.

DBCC TRACEON(3604)

Next I will be using the undocumented trace flags 8608 and 8615 but, although I can still use DBCC TRACEON, this time I will use the also undocumented QUERYTRACEON query hint. Please bear in mind that all these are undocumented SQL Server statements and should not be used on a production environment.

The first trace flag, 8608, will show the initial memo structure, which you can see in the Messages tab of the Query window in Management Studio.

SELECT e.EmployeeID FROM HumanResources.Employee AS e 
INNER JOIN Sales.SalesPerson AS s ON e.EmployeeID = s.SalesPersonID
OPTION (QUERYTRACEON 8608)

Running the previous query will show the following output

--- Initial Memo Structure ---
Root Group 5: Card=8.33333 (Max=10000, Min=0)
   0 LogOp_Join 0 1 4 
Group 4: 
   0 ScaOp_Comp  2 3 
Group 3: 
   0 ScaOp_Identifier  
Group 2: 
   0 ScaOp_Identifier  
Group 1: Card=17 (Max=10000, Min=0)
   0 LogOp_Get 
Group 0: Card=290 (Max=10000, Min=0)
   0 LogOp_Get

The next query uses trace flag 8615 to display the final memo structure

SELECT e.EmployeeID FROM HumanResources.Employee AS e 
INNER JOIN Sales.SalesPerson AS s ON e.EmployeeID = s.SalesPersonID
OPTION (QUERYTRACEON 8615)

which shows the following output

--- Final Memo Structure ---
Group 9: Card=1 (Max=1, Min=0)
   0 LogOp_SelectIdx 8 4 
Group 8: Card=17 (Max=10000, Min=0)
   0 LogOp_GetIdx 
Group 7: Card=1 (Max=1, Min=0)
   1 PhyOp_Range 1 ASC 4.0 Cost(RowGoal 0,ReW 0,ReB 16,Dist 17,Total 17)= 0.0058127
   0 LogOp_SelectIdx 6 4 
Group 6: Card=290 (Max=10000, Min=0)
   0 LogOp_GetIdx 
Root Group 5: Card=8.33333 (Max=10000, Min=0)
   2 PhyOp_Applyx_jtInner 1.2 7.1 Cost(RowGoal 0,ReW 0,ReB 0,Dist 0, …)= 0.00918446
   1 LogOp_Join 1 0 4 
   0 LogOp_Join 0 1 4 
Group 4: 
   0 ScaOp_Comp  2.0 3.0  Cost(RowGoal 0,ReW 0,ReB 0,Dist 0,Total 0)= 3
Group 3: 
   0 ScaOp_Identifier   Cost(RowGoal 0,ReW 0,ReB 0,Dist 0,Total 0)= 1
Group 2: 
   0 ScaOp_Identifier   Cost(RowGoal 0,ReW 0,ReB 0,Dist 0,Total 0)= 1
Group 1: Card=17 (Max=10000, Min=0)
   3 PhyOp_Range 1 ASC   Cost(RowGoal 0,ReW 0,ReB 0,Dist 0,Total 0)= 0.0033007
   2 PhyOp_Range 2 ASC   Cost(RowGoal 0,ReW 0,ReB 0,Dist 0,Total 0)= 0.0033007
   0 LogOp_Get 
Group 0: Card=290 (Max=10000, Min=0)
   0 LogOp_Get

You can notice that among other things the output shows information about operators, groups, cardinality information (Card) and cost estimation. I will be discussing a few more undocumented trace flags on a second post very soon.

Disabling Parameter Sniffing?

As I mentioned in a previous post, parameter sniffing is a good thing: it allows you to get an execution plan tailored to the current parameters of your query. Of course, sometimes it can also be a problem but there are some solutions available. Some of these solutions are covered in my posts here and here.

However, Microsoft recently released a cumulative update which provides a trace flag to disable parameter sniffing at the instance level. This cumulative update is available for the latest versions of SQL Server as described on the knowledge base article 980653.

Basically this trace flag, 4136, has the effect of disabling the use of histograms, a behavior similar to the use of the OPTIMIZE FOR UNKNOWN hint. There are still three cases where this trace flag has no effect, as described in the previous knowledge base article, which are on queries using the OPTIMIZE FOR or RECOMPILE query hints and on stored procedures using the WITH RECOMPILE option.

In general I would not recommend using this trace flag and would ask you to try the other solutions available instead. But anyway, it is good to know that this choice exists and can be used in cases when you really need it. It should be used carefully and only when enough testing shows that in fact it improves the performance of your application.

But let us test it to see how it works. I am testing it with SQL Server 2008 R2. My original build is 10.50.1600. After the cumulative update is installed the build is 10.50.1720.

Let us use the same example described on my OPTIMIZE FOR UNKNOWN post so perhaps you want to refer to it to better understand the details. Create the following stored procedure on the AdventureWorks database.

CREATE PROCEDURE test (@pid int)

AS

SELECT * FROM Sales.SalesOrderDetail

WHERE ProductID = @pid

Executing the stored procedure before the cumulative update, or after the cumulative update but without using the flag

EXEC test @pid = 709

shows the following plan

clip_image002

In this case, since the trace flag is not yet in effect, SQL Server uses the statistics histogram to estimate the number of rows which in this case is 188. After I enable the trace flag, restart my SQL Server instance, and run the same stored procedure again I got the following plan where the estimated number of rows is now 456.079. Again, how these values were obtained was explained in my previous post.

clip_image004

Let us try a test using the OPTIMIZE FOR query hint, which ignores the 4136 trace flag (note that it is not the same as the OPTIMIZE FOR UNKNOWN hint) by using the following code.

ALTER PROCEDURE test (@pid int)

AS

SELECT * FROM Sales.SalesOrderDetail

WHERE ProductID = @pid

OPTION (OPTIMIZE FOR (@pid = 709))

If you try this version of the stored procedure, even with the trace flag enabled, it will use the histogram again and will create a plan using the estimated number of rows of 188.

Finally, if you followed this exercise, do not forget to remove the trace flag and restart your SQL Server service.

Avoiding Backup Messages on the Error Log

One of the most useful trace flags I use on my SQL Server instances is trace flag 3226, which prevents SQL Server from writing those successful backup messages to the error log. By default, every time a database backup of any type is completed successfully, a message similar to the following is written to the SQL Server error log.

Log was backed up. Database: Test, creation date(time): 2010/06/28(14:53:06), first LSN: 21:2235:1, last LSN: 21:2235:1, number of dump devices: 1, device information: (FILE=3, TYPE=DISK: …

So when you perform many backups, especially transaction log backups, and/or have many databases on the same instance, the SQL Server error log could contain hundreds or thousands of these messages in a way that it can become difficult to find any other useful information there. When this trace flag is used, backup messages are no longer written to the error log or the system event log.

Although this trace flag had been available since SQL Server 2000, most of us learned about it until 2007 when both Andy Kelly and Kevin Farlee blogged about it. At the time it was undocumented but it is now totally documented, appearing on the Trace Flags entry of Books Online.

Trace flags can be set on and off by using the DBCC TRACEON and DBCC TRACEOFF commands or by using the -T startup option, although the latest choice is more appropriate for this specific case. One way to use –T startup option is by right-clicking on the SQL Server service using Configuration Manager, selecting Properties and the Advanced tab, and adding ;-T3226 to the Startup Parameters entry as shown in the next figure. Finally, you will be required to restart your SQL Server service for this configuration change to take effect.

clip_image002