Recently one of my customers were not able to achieve the desired throughput (transactions per sec) from their Java based OLTP application which is used to pump the data load in sql database
To identify the performance issue, we had setup a stress testing environment to simulate a user workload with think time of 2 sec. In Parallel, we captured SQLDIAG while generating the user load.
Further, we used SQL Nexus Reports to analyze the SQL DIAG and following is the snapshot of result and wait stats
From the Report, we clearly see the Head blocker is max blocking chain size had grown to 220899 with total blocking duration of 987 sec which comes to 16 mins.
The Blocking chain was severely impacting the throughput of the application.
As you see, the Head Blocker as well as the blocked session are waiting on Compile Locks.
In Microsoft SQL Server, only one copy of a stored procedure plan is generally in cache at a time. Enforcing this requires serialization of some parts of the compilation process, and this synchronization is accomplished in part by using compile locks. If many connections are concurrently running the same stored procedure and a compile lock must be obtained for that stored procedure every time that it is run, system process IDs (SPIDs) might begin to block one another as they each try to obtain an exclusive compile lock on the object.
I checked and confirmed that we were not hitting any of the issues mentioned in the KB http://support.microsoft.com/kb/263889
We were using two part naming convention as well the case of the SP call matched the SP definition case and hence above issues were ruled out.
So we captured profiler trace, while executing the Stored Procedure and we observed the following events in the profiler
From, the above set of event in profiler, we understand that after SP execution starts, we see an User Error Message (also referred as user exception) after which we see SP:Cachemiss event.
SP:CacheMiss event explain why does SP goes for compilation on each execution which inturn results in COMPILE lock blocking.
Now to understand why we receive SP:CacheMiss event, we check the User Error Message event received before CacheMiss event
Error: 156, Severity: 15, State: 1
Incorrect syntax near the keyword ‘SET’.
Executing SQL directly; no cursor.
The RPC Call captured in the profiler trace is
declare @p1 int
set @p1=0
declare @p2 int
set @p2=0
declare @p7 int
set @p7=0
exec sp_cursorprepexec @p1 output,@p2 output,NULL,N’EXEC ‘,16,8193,@p7 output
select @p1, @p2, @p7
When I execute the above query directly, I don’t see any error message as captured by Profiler above.
When we call the same SP using the Java application which uses server side cursor call sp_cursorprepexec it gives the above User Error Message event in profiler and hence SP:CacheMiss. Also the ‘SET’ keyword mentioned above in the error message is the first statement of the SP definition since the first statement in the SP is SET NOCOUNT ON, if I remove the SET option, I receive error message for DECLARE which then becomes the first statement of the SP definition.
So why do we receive the User Error Message in Profiler when we run the same SP using Java Application?
The issue was caused due to use of Server Side Cursor which has restrictions on execution of TSQL syntax as the SP which we were executing was primarily performing inserts while we were hitting one of these restriction. In order to resolve the issue we had to change the selectMethod setting in the JDBC driver connection string to selectMethod=direct.
After avoiding Server side cursor by setting selectMethod=direct, there were no User Exception Messages and hence no SP:CacheMiss (saw SP:Cachehit in profiler) which eliminated the COMPILE locking on the server and thereby we were able to see an increase in Transactions per second for the customer.
Hope this helps !!!
Parikshit Savjani
Premier Field Engineer