Parameter sniffing in SQL Server 2005/2008 (using Project Server 2007 as an example)

    Faced an interesting error on a loaded Project Server 2007. Moreover, it manifests itself with active use (read, in the product). During development, debugging and testing, this error did not appear even once. Even worse, when an error occurs, SQL "wedges", and without extraneous intervention, the error does not disappear. Well, in the end - from the logs it is extremely difficult to understand the reason for its occurrence. Google, unfortunately, did not help, which, in fact, prompted me to write about this problem.
    If you got an unexpected error on the project details page, and the error 7888 (SQL Timeout) is in the log, then welcome to cat. If you are interested in the internal “ego” of SQL Server, it is also worth reading.

    Anamnesis


    The error occurs when viewing project information (http: //server/pwa/ProjectDrillDown.aspx) in Project Server 2007 Web Access (PWA), and it is when working with PWA> 1 person (specific conditions are not set). It appeared on different Windows Server (2003 / 2008R2) and on different SQL Server (2005 / 2008R2).
    The page displays:
    “An unexpected error has occurred.
    Web Parts Maintenance Page: If you have the appropriate permissions, you can use this page to temporarily close web parts and delete personal settings. For more information, contact the site administrator. ”
    (In the English version: “An unexpected error has occurred. [...]”)

    In the event log of OS applications:
    Runtime exception. See below for more information.
    Message: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
    Technical Details:
    System.Data.SqlClient.SqlException: Timeout expired. The timeout period elapsed prior to completion of the operation or the server is not responding.
    at System.Data.SqlClient.SqlConnection.OnError (SqlException exception, Boolean breakConnection)
    at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning (TdsParserStateObject stateObj)
    at System.Data.SqlClient.TdsParserhdrdbdhrd Run , BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
    System.Data.SqlClient.SqlDataReader.ConsumeMetaData AT ()
    AT System.Data.SqlClient.SqlDataReader.get_MetaData ()
    AT System.Data.SqlClient.SqlCommand.FinishExecuteReader (the SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
    AT the System.Data.SqlClient .SqlCommand.RunExecuteReaderTds (CommandBehavior cmdBehavior, runBehavior runBehavior, returnStream Boolean, Boolean async)
    at System.Data.SqlClient.SqlCommand.RunExecuteReader (CommandBehavior cmdBehavior, runBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result)
    at System.Data.SqlClient. SqlCommand.RunExecuteReader (CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method)
    at System.Data.SqlClient.SqlCommand.ExecuteReader (CommandBehavior behavior, String method)
    at System.Data.SqlClient.SqlCommand.ExecuteDbDataReader (CommandBehavior behavior)
    at System.Data.Common.DbCommand.System.Data.IDbCommand.ExecuteReader behavior (CommandBehh )
    at System.Data.Common.DbDataAdapter.FillInternal (DataSet dataset, DataTable [] datatables, Int32 startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
    at System.Data.Common.DbDataAdapter.Fill (DataSet dataSet, Int startRecord, Int32 maxRecords, String srcTable, IDbCommand command, CommandBehavior behavior)
    at System.Data.Common.DbDataAdapter.Fill (DataSet dataSet)
    at Microsoft.Office.Project.Server.DataAccessLayer.DAL.SubDal.FillTypedDataSet (DataSet typedDataSet, String [] tables, SqlCommand sqlCommand)
    at Microsoft.Office.Project.Server.DataAccessLayer.DAL.SubDal.FillTypedSetDetSetDataSet (Data ] tables, String storedProcedureName, SqlParameter [] parameters)
    at Microsoft.Office.Project.Server.DataAccessLayer.Generated.ViewDalBase.GetViewReportsByType (Int32 p0, Guid tsUIDprojUID, Guid res_uid)
    at Microsoft.Office.Project.Server. GetViewReportsByType (ViewType viewType, Guid tsUID)
    at Microsoft.Office.Project.Server.WebService.PWA.ViewGetViewReportsByType (ViewType viewType, Guid tsUID)


    In the ULS log of SharePoint (\ Program Files \ Common Files \ Microsoft Shared \ Web Server Extensions \ 12 \ LOGS \), no new information was found by mistake. By the way, I recommend SharePoint ULS Log Viewer for reading logs .

    The total that I managed to find out:
    1. An error occurs in the file "ProjectDrillDown.aspx" and once it appears, it is not treated itself.
    2. An error occurs when the ViewGetViewReportsByType method is called and ends with SqlException: Timeout expired.
    3. Changing the timeout time at the SharePoint farm level (stsadm -o setproperty -pn database-connection-timeout -pv 60) has no effect.
    4. Changing the timeout time at the instance level of SQL "resets the error", but it reappears very quickly. As a temporary hut, SQL was fastened to Job, which changes the instance parameters every few minutes.

    Survey


    1. Deep googling, picking regular means, attempts to artificially reproduce the error and understand the causes of its occurrence were unsuccessful.
    2. Catching by SQL Profiler also failed: on a loaded system an unrealistic number of queries (even when filtering), and on an unloaded one - an error does not occur.
    3. I had to remove the library “Microsoft.Office.Project.Server.WebService.PWA.dll” from the GAC and gut it using .Net Reflector . The required ViewGetViewReportsByType method called several more and in the end I found a buggy SQL query. It turned out to be a request (through several other storage options) to the table function MSP_WEB_FN_SEC_GetAllObjectsResCanViewByViewIDInfo of the ProjectServer_Published database.
    4. Here I had to get a tambourine: UDF is written fine, there is no information on the internet about it. But the miracle: you call this function or build the Execution Plan in SQL Management Studio - and everything starts to work!

    Total: the problem is in the table function MSP_WEB_FN_SEC_GetAllObjectsResCanViewByViewIDInfo.

    Analysis


    For a long time I couldn’t understand what’s the matter ...
    But the matter was in the cunning cache of the MSSQL Server and the crooked hands of the webpart writers (wired in ActiveX) for Project Server 2007.
    The fact is that when executing queries (including storages), SQL Server creates for them, Execution Plan and puts it in the cache. At the following requests, they are not compiled, but are taken from the cache (not always). As a result, with some query from Project Server (it was not clear at what) SQL compiled the Execution Plan for the function MSP_WEB_FN_SEC_GetAllObjectsResCanViewByViewIDInfo through the ass, which caused a timeout. And, of course, until you reset the cache (by changing the database parameters or recompiling the function) - Project Server will not work.

    Lobotomy


    The specified function inside contains cursors and calls to five frequently changing tables, returns tables of different sizes (depending on input parameters), and builds queries with different Execution Plan. And the latter, for the normal operation of this function, should not depend on the input parameters (the so-called parameter sniffing). Treatment options:
    - compilation of the function every time before the request;
    - fixing a specific "correct" Execution Plan without auto-update;
    - Disabling parameter sniffing by rewriting external variables into internal ones.
    The first two options are suitable only for procedures (via the OPTION or WITH parameter), so crutches were prescribed to the patient (third option). I bring the changed part of the function, added variables with the _parameter postfix:

    ALTER FUNCTION [dbo].[MSP_WEB_FN_SEC_GetAllObjectsResCanViewByViewIDInfo] (
    @res_guid_parameter uniqueidentifier,
    @fea_act_uid_parameter uniqueidentifier,
    @fAllow_parameter int,
    @obj_type_uid_parameter uniqueidentifier,
    @view_uid_parameter uniqueidentifier
    )
    RETURNS @ret_obj_rule_info_tbl table (WSEC_RULE_INFO int, WSEC_CAT_UID uniqueidentifier)
    AS
    BEGIN
    — local variables to disable parameter sniffing
    declare @res_guid uniqueidentifier
    declare @fea_act_uid uniqueidentifier
    declare @fAllow int
    declare @obj_type_uid uniqueidentifier
    declare @view_uid uniqueidentifier
    set @res_guid = @res_guid_parameter
    set @fea_act_uid = @fea_act_uid_parameter
    set @fAllow = @fAllow_parameter
    set @obj_type_uid = @obj_type_uid_parameter
    set @view_uid = @view_uid_parameter
    [...]


    Prevention


    All programmers working with SP / UDF, as well as all DBAs, highly recommend reading the following articles:
    1. Parameter Sniffing & Stored Procedures Execution Plan . A competent article on "parameter sniffing" as early as 2006, relevant until now.
    2. Batch Compilation, Recompilation, and Plan Caching Issues in SQL Server 2005 . The official description of the internal behavior of SQL Server.
    3. There was an article on the hub with this problem, but almost no one was interested: MS SQL 2005, Parameter Sniffing, which slows down the Stored Procedure .

    PS


    The error also appeared on the platform with the latest SP: WS2008R2 / SQL2008R2 / MOSS2007SP2 / MOPS2007SP2.

    UPD 02/25/2011: the error text is fixed.

    Also popular now: