Faced with an interesting error on the loaded Project Server 2007. And 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, the SQL “overlaps”, and without outside intervention, the error does not disappear. Well, in the end - from the logs is extremely difficult to understand the cause of its occurrence. Google, unfortunately, did not help, which, in fact, prompted to write about this issue.
If you have an unexpected error on the project information page, and error 7888 (SQL Timeout) in the log, welcome under cat. If you are interested in the internal "ego" of SQL Server - 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 (no specific conditions have been set). It was shown on different Windows Server (2003 / 2008R2) and on different SQL Server (2005 / 2008R2).
The page displays:
“An unexpected error occurred.
Web Part Maintenance page: With the appropriate permissions, you can temporarily close Web Parts and delete personal settings using this page. For more information, contact your site administrator. ”
(In the English version: “An unexpected error has occurred. [...]”)
In the event OS application log:
Exception at run time. See below for more details.
Message: Timeout expired. The timeout period is not responding.
Technical Details:
System.Data.SqlClient.SqlException: Timeout expired. The timeout period 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.TdsParser. Run (RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj)
at System.Data.SqlClient.SqlDataReader.ConsumeMetaData ()
at System.Data.SqlClient.SqlDataReader.get_MetaData ()
at System.Data.SqlClient.SqlCommand.FinishExecuteReader (SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString)
at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds (CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, 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 (CommandBehavior behavior)
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, Int32 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.FillTypedDataSet (DataSet typedDataSet, String [] 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.BusinessLayer.View.GetViewReportsByType (ViewType viewType, Guid tsUID)
at Microsoft.Office.Project.Server.WebService.PWA.ViewGetViewReportsByType (ViewType viewType, Guid tsUID)
In the SharePoint ULS log (\ Program Files \ Common Files \ Microsoft Shared \ Web Server Extensions \ 12 \ LOGS \) no new information was found by mistake. By the way, for reading logs I advise
SharePoint ULS Log Viewer .
')
Total that 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 calling the ViewGetViewReportsByType method and ends with a 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 SQL instance level “clears the error,” but it reappears very quickly. As a makeshift, a Job was screwed to SQL, which changes the instance parameters every few minutes.
Survey
1. Deep googling, picking up standard tools, attempts to artificially reproduce the error and understand the reasons for its occurrence were not crowned with success.
2. Catching SQL Profiler also failed: unrealistic number of requests on the loaded system (even when filtering), and unloaded - the error does not manifest.
3. I had to remove the “Microsoft.Office.Project.Server.WebService.PWA.dll” library from the GAC and gut it using
.Net Reflector . The required method ViewGetViewReportsByType called a few more and as a result I found a buggy SQL query. It turned out to be a query (through several other storages) to the table function MSP_WEB_FN_SEC_GetAllObjectsResCanViewByViewIDInfo of the ProjectServer_Published database.
4. Then I had to get a tambourine: UDF is written normally, there is no information in the internet about it. But a miracle: you call this function or build Execution Plan in SQL Management Studio - and everything starts working!
Total: problem in the table function MSP_WEB_FN_SEC_GetAllObjectsResCanViewByViewIDInfo.
Analysis
I could not understand what was happening ...
And it was in the smart-cache MSSQL Server cache and the crooked hands of WebPart writers (sewn into ActiveX) for Project Server 2007.
The fact is that when executing queries (including stored ones), SQL Server creates an Execution Plan for them and puts it into the cache. With the following requests, they are not compiled, but taken from the cache (not always). As a result, at some request from Project Server (it was not clarified at what) SQL compiled Execution Plan for MSP_WEB_FN_SEC_GetAllObjectsResCanViewByViewIDInfo function 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 references 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:
- compile the function each time before the request;
- consolidation of a specific "correct" Execution Plan without auto-update;
- disable parameter sniffing by rewriting external variables into internal ones.
The first two options are suitable only for procedures (through the parameter OPTION or WITH), so the crutches were prescribed to the patient (the third option). I give 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
I highly recommend reading the following articles to all programmers working with SP / UDF, as well as all DBAs:
1.
Parameter Sniffing & Stored Procedures Execution Plan . Competent article on "parameter sniffing" already in 2006, still relevant.
2.
Batch Compilation, Recompilation, and Plan Caching Issues in SQL Server 2005 . The official description of the internal behavior of SQL Server.
3. On Habré there was an article with this problem, but almost no one became interested in:
MS SQL 2005, Parameter Sniffing, inhibiting the Stored Procedure .
PS
The error also manifested itself on the platform with the latest SP: WS2008R2 / SQL2008R2 / MOSS2007SP2 / MOPS2007SP2.
UPD 02.25.2011: corrected the error text.