What is in my statement cache?
I was talking with one of our customers the other day who had a whole bunch of disparate applications attaching to his server.
It really is not unusual from what I have seen to have legacy applications connecting to ASE that the DBA has no knowledge of at all, things just ‘work’ 🙂 .
Anyway, from what I explained I thought it would be worth detailing here, there are specific formats and properties of the various entries in
the statement cache that help identify the possible setup of the source application.
We have enhancements in 15.7 and above to allow dynamic sql to be stored in the regular statement cache also (more on that below).
The statement cache stores the statement text object, the LWPs (lightweight procedures) themselves reside in the procedure cache.
Note that monCachedProcedures\monCachedStatement are the two MDA tables relevant to looking at the individual LWPs.
Here I am making use of of a few things…
show_cached_text(<ssql_id>) –ssql_id being the id of the statement in the statement cache (also the lwp procedure id)
dbcc prsqlcache (<ssql_id>, 0||1) –ssql_id is optional but without it will print the whole statement cache. 1 for second parameter will show query plan in showplan format.
show_cached_plan_in_xml(<ssql_id>,0,6) –very useful, this can display for you the compile time bind values as well as execution time bind values.
..Ok so I’m not actually using this last one for the purposes of this post, but thought it was definitely worth mentioning, it’s a great addition.
The ssql_id of a statement can be found in the showplan output or you can actually search monCachedStatement based on the statement text.
The configuration option ‘enable stmt cache monitoring’ will need to be enable to run the queries against monCachedStatement.
This exposes a number of other fields that we now store with the entry in the statement cache, and in fact are key players
when it comes to identifying the correct statement on subsequent executions, more later..
select mp.ObjectName, PlanID,QuotedIdentifier,convert (char(100),show_cached_text(ms.SSQLID)),UseCount,StmtType,SSQLID,Hashkey from monCachedStatement ms, monCachedProcedures mp
where ms.SSQLID=mp.ObjectID
and show_cached_text(ms.SSQLID) like ‘select id from sysobjects%’ –yeh, I know..not the best query
Also, I would strongly suggest not querying the MDA tables like this directly on a production server, make persistent copies of the data and then query those
tables.
ObjectName PlanID QuotedIdentifier TransactionIsolationLevel UseCount StmtType SSQLID Hashkey
—————————— ———– —————- ————————- ———————————————————————- ———– ——– ———– ———–
*ss0883087873_1444758355ss* 216 0 1 select id from sysobjects where id =@@@V0_INT(@@@V0_INT INT) 1 1 883087873 1444758355
*ss0227085536_1999730024ss* 128 0 1 select id from sysobjects where id=@@@V0_INT(@@@V0_INT INT) 1 1 227085536 1999730024
*ss0243085593_1258308435ss* 130 0 1 select id from sysobjects where id= @@@V0_INT(@@@V0_INT INT) 2 1 243085593 1258308435
*ss0259085650_1191925839ss* 132 0 1 select id from sysobjects where id = @@@V0_INT(@@@V0_INT INT) 2 1 259085650 1191925839
*ss0931088044_1309953367ss* 222 0 1 select id from sysobjects where id = 1 1 1 931088044 1309953367
*ss1075088557_1046503768ss* 240 0 1 select id from sysobjects where id= @simon(@simon INT output) 1 1 1075088557 1046503768
*ss1059088500_1394150455ss* 238 1 1 select id from sysobjects where id= @p0(@p0 INT output) 1 1 1059088500 1394150455
*ss0067084966_1394158647ss* 104 1 1 select id from sysobjects where id= @P0(@P0 INT output) 4 1 67084966 1394158647
*ss0419086220_0208369987ss* 151 1 1 select id from sysobjects where id= @dr_ta0(@dr_ta0 INT output) 1 1 419086220 208369987
*ss0467086391_0208369987ss* 161 0 1 select id from sysobjects where id= @dr_ta0(@dr_ta0 INT output) 2 1 467086391 208369987
*ss0547086676_1393102647ss* 171 0 1 select id from sysobjects where id= @s(@s INT output) 1 1 547086676 1393102647
*ss1027088386_1394150455ss* 234 1 0 select id from sysobjects where id= @p0(@p0 INT output) 1 1 1027088386 1394150455
*ss1155088842_1664707590ss* 250 1 1 select id from sysobjects where id= @0001(@0001 INT output) 1 1 1155088842 1664707590
The next lot will only be seen with ‘streamlined dynamic SQL’ = 1.
Part of the enhancement under this option was that dynamically prepared statements which previously were only available in a connection
specific dynamic sql cache are now able to be stored in the regular statement cache to be shared across connections.
*sq0051084909_1393122376ss* 157 1 1 select id from sysobjects where id= ? 19 3 51084909 1393122376
*sq0051084909_1393122376ss* 197 1 1 select id from sysobjects where id= ? 19 3 51084909 1393122376
*sq0947088101_1393122376ss* 224 1 0 select id from sysobjects where id= ? 1 3 947088101 1393122376
*sq0627086961_1393122376ss* 181 0 1 select id from sysobjects where id= ? 3 3 627086961 1393122376
*sq0083085023_1394150455ss* 106 1 1 select id from sysobjects where id= @p0 2 2 83085023 1394150455
*sq0387086106_0208369987ss* 145 1 1 select id from sysobjects where id= @dr_ta0 1 2 387086106 208369987
*sq0611086904_1393102647ss* 179 0 1 select id from sysobjects where id= @s 1 2 611086904 1393102647
*sq0867087816_1664707590ss* 214 1 1 select id from sysobjects where id= @0001 1 2 867087816 1664707590
*sq0915087987_1309953367ss* 220 0 1 select id from sysobjects where id = 1 1 2 915087987 1309953367
If your clients are standard ct-lib isql, then the most common form of statement you will see in the statement cache is an entry with the three ampersands
as the prefix of the variable name. These will be generated when ‘enable literal parameterization’ is enabled at the server-level or literal_autoparam is on at session level. You may also see these generated from any client application issuing statements with fixed (non parameterised at client-side) search arguments.
These statements may be regular or prepared, but crucially, not ‘dynamically’ prepared – more on that in a bit.
select id from sysobjects where id =@@@V0_INT(@@@V0_INT INT)
select id from sysobjects where id=@@@V0_INT(@@@V0_INT INT)
select id from sysobjects where id= @@@V0_INT(@@@V0_INT INT)
select id from sysobjects where id = @@@V0_INT(@@@V0_INT INT)
All with a name of *ss<ssql_id>_<hashkey>ss*
I’m not going to go into literal parameterisation in this post, but to put it simply it takes constant search arguments and replaces them with parameters
to enable the plan to be re-used for a different set of search arguments, in essence to cut down on compilation overhead. Lots of good stuff in this area
that could be discussed but not here and now.
Note the differing white space around the equality operator, having no white space on either side of the operator will form a unique statement, more than
one space though and they’ll be stripped and it’ll get lumped in with the single space ‘versions’. Comments are kept with the statement (and are used in hashkey generation) if they are sent to the ASE.
Note these all have a StmtType of 1, these are all language statements or ad-hoc sql (from the perspective of the server), their lwp name will start with *ss
select id from sysobjects where id = 1
This one is a regular statement but with no literal parameterisation.
Next we have what we call parameterised language statements, these can of course be ad-hoc queries using a declared variable (the first example):-
select id from sysobjects where id= @simon(@simon INT output)
If you see the following naming convention for the variables, then this is likely jConnect JDBC driver (jconn3.jar (6.x) or jconn4.jar (7.x)):-
select id from sysobjects where id= @p0(@p0 INT output)
Parameterised language statements may be sent from pretty much any client (ODBC,JDBC, ADO.NET,OLEDB, ct-lib, esql etc) and are likely to either
be prepared statements with unnamed placeholders, i.e. a question mark (but not dynamically prepared), or statements which were intended to be dynamically prepared that the server didn’t permit ( ? placed in the wrong place).
Upper case P used by jTDS driver:-
select id from sysobjects where id= @P0(@P0 INT output)
Note the number suffix will be incremented dependant on the number of variables in the statement.
ODBC driver (native Sybase ODBC)\ OLEDB driver \ ADO.NET driver (for the ADO.NET ? can only be used with NamedParameters=false):-
select id from sysobjects where id= @dr_ta0(@dr_ta0 INT output)
If you look the the next one in the list, you’ll see it has the same hashkey as the one above. The difference here is the quoted_identifiers option.
If this is set it will create a new lwp.
Next:-
select id from sysobjects where id= @s(@s INT output)
This is just a statement using named parameters – AseCommand.Parameters.Add(“@s”, SqlDbType.Int).Value = 1 for .NET driver for example.
Most APIs have a way of doing this.
The next one again appears to be a repeat statement, ah, but hang on it has a different isolation level.
Before 15.7, change of isolation level was a trigger to bump the schemacnt and recompile, but not any more, it will generate a new lwp.
This also applies to optimization goal & optimization level – NOTE this is relevant for statement cache lwps not stored procedures.
Next:-
select id from sysobjects where id= @0001(@0001 INT output)
This is usually the format seen with the older DataDirect odbc drivers (dare I speak of them 🙂 ).
Now we have a few of these:-
select id from sysobjects where id= ?
The first two are in fact exactly the same, check the lwp name, the two rows represent 2 query plans, i.e. one was in-use so we had to compile
another (or clone on later versions).
These are dynamically prepared statements, ct_dynamic from ct-lib, SQLPrepare from native ODBC, PreparedStatement in JDBC, Ase\Odbc\OleDbcommand.Prepare().
OLEDB\ODBC\jConnect with whatever property determines this for the relevant connection string (DYNAMICPREPARE=1\DYNAMIC_PREPARE=true).
You will only see question marks as search arguments (with no quotes) from dynamically prepared statements.
They have a StmtType of 3.
They will be sent by the client as create proc statements with an external name to communicate with the server, don’t get
confused by the statements you may see in monSysSQLText, these may look something like
create proc myquery –custom name set in ct_dynamic call
create proc jtds000001 –jtds
create proc dyn100 –jdbc, possibly other on some versions
create proc A0 – ODBC\OLEDB
These are pretty much meaningless from a debug perspective, the internal name of the lwp stored begins with *sq.
See above, all of these are now in the statement cache and that is down to ‘streamlined dynamic SQL’. Without
that feature enabled you will not see dynamic prepared statements in the statement cache.
Finally, lets look the final five, these begin with *sq but look like regular ad-hoc queries, or rather parameterised language statements.
Note the StmtType=2, this means they are cursors, specifically either straight language based cursor or TDS cursors based on a language
statement. An lwp is created for the cursor, which means it is converted to a procedural cursor (or execute cursor).
This is also a ‘streamlined dynamic SQL’ enhancement.
I’m in danger of getting too much into the nitty gritty here but feel we need to make the job complete!
You won’t see a StmtType=2 for a dynamically prepared statement (that uses cursors) as the cursor is declared on top of the external lwp name, not the
language statement under the external lwp.
Cursors will be used if the correct method for whatever API is called to make it a cursor – or the correct connection parameter is set (UseCursor=1 for ODBC\OLEDB, IMPLICIT_CURSOR_FETCH_SIZE=<X>\SELECT_OPENS_CURSOR=true for jConnect).
The very last entry there is a regular ad-hoc declare cursor\open cursor (which will not go through literal parameterisation by the way)
just to show that the *sq lwps are not necessarily restricted to the premise of a prepared statement, although as already demonstrated they *usually* are.
If you made it this far hopefully you found something useful you can take away!
Whilst implementing some statement cache monitoring I came across a bit of an oddity with the dbcc prsqlcache (<lwpid>, 1) command I mentioned above.
If there are multiple plans in cache for a given lwp, it will only print you out the first plan (the first PROCBUF in the procedure cache chain for that lwp). I think I've fallen for this before thinking the 'bad' plan may have been lost when debugging at a later point, whereas in reality it may well have still been there, just not exposed to prsqlcache.
Needless to say I was a bit miffed as it's quite nice to get the traditional showplan outputs. A CR will be logged with SAP to improve the dbcc command to print all the query plans.
However..
As part of the monitoring we're also pulling out the details for the plans using show_cached_plan_in_xml() against each plan available in monCachedProcedures. It turns out that this built-in function can actually be used to allow dbcc prsqlcache to read each plan in turn.
When you call show_cached_plan_in_xml() it has to read the PROCBUF and as such the plan you are reading is placed at the MRU end of the chain. This means when you call dbcc prsqlcache again you now get that plan displayed.
This method can also allow you to force a statement to use a particular plan in circumstances where you do have more than one available in the statement cache (this is potentially very useful indeed).
Below you can see lwp id (107558527) using a specific plan (index scan on notblocky):
3:1> select * from blocky, notblocky where blocky.b1=notblocky.b1
3:2> go
QUERY PLAN FOR STATEMENT 1 (at line 1).
STEP 1
The type of query is EXECUTE.
Executing a previously cached statement (SSQL_ID = 107558527).
QUERY PLAN FOR STATEMENT 1 (at line 1).
Optimized using Serial Mode
STEP 1
The type of query is SELECT.
3 operator(s) under root
|ROOT:EMIT Operator (VA = 3)
|
| |NESTED LOOP JOIN Operator (VA = 2) (Join Type: Inner Join)
| |
| | |SCAN Operator (VA = 0)
| | | FROM TABLE
| | | blocky
| | | Index : ix
| | | Forward Scan.
| | | Positioning at index start.
| | | Index contains all needed columns. Base table will not be read.
| | | Using I/O Size 2 Kbytes for index leaf pages.
| | | With LRU Buffer Replacement Strategy for index leaf pages.
| |
| | |SCAN Operator (VA = 1)
| | | FROM TABLE
| | | notblocky
| | | Index : ix
| | | Forward Scan.
| | | Positioning by key.
| | | Index contains all needed columns. Base table will not be read.
| | | Keys are:
| | | b1 ASC
| | | Using I/O Size 2 Kbytes for index leaf pages.
| | | With LRU Buffer Replacement Strategy for index leaf pages.
Print the plan:
5:1> dbcc prsqlcache (107558527,1)
5:2> go
QUERY PLAN FOR STATEMENT 1 (at line 1).
STEP 1
The type of query is DBCC.
SSQL_DESC 0x0x3078ad130
ssql_name *ss0107558527_2003073569ss*
ssql_hashkey 0x0x77647a21 ssql_id 107558527
ssql_suid 1 ssql_uid 1 ssql_dbid 2 ssql_spid 0
ssql_status 0x0xa0 ssql_parallel_deg 1
ssql_isolate 1 ssql_tranmode 32
ssql_keep 0 ssql_usecnt 20 ssql_pgcount 14
ssql_optgoal allrows_oltp ssql_optlevel ase_current
opt options bitmap 00809f172c61f5ffff7f37ffdfff7f870300000000000000000000000000
SQL TEXT: select * from blocky, notblocky where blocky.b1=notblocky.b1
QUERY PLAN FOR STATEMENT 1 (at line 1).
Optimized using Serial Mode
STEP 1
The type of query is SELECT.
3 operator(s) under root
|ROOT:EMIT Operator (VA = 3)
|
| |NESTED LOOP JOIN Operator (VA = 2) (Join Type: Inner Join)
| |
| | |SCAN Operator (VA = 0)
| | | FROM TABLE
| | | blocky
| | | Index : ix
| | | Forward Scan.
| | | Positioning at index start.
| | | Index contains all needed columns. Base table will not be read.
| | | Using I/O Size 2 Kbytes for index leaf pages.
| | | With LRU Buffer Replacement Strategy for index leaf pages.
| |
| | |SCAN Operator (VA = 1)
| | | FROM TABLE
| | | notblocky
| | | Index : ix
| | | Forward Scan.
| | | Positioning by key.
| | | Index contains all needed columns. Base table will not be read.
| | | Keys are:
| | | b1 ASC
| | | Using I/O Size 2 Kbytes for index leaf pages.
| | | With LRU Buffer Replacement Strategy for index leaf pages.
Take a look in monCachedProcedures, there are 2 plans, 81900 and 81896:
7:1> select * from master..monCachedProcedures where ObjectID=107558527
7:2> go
ObjectID InstanceID OwnerUID DBID PlanID MemUsageKB CompileDate ExecutionCount CPUTime ExecutionTime PhysicalReads LogicalReads PhysicalWrites PagesWritten ObjectName ObjectType OwnerName DBName RequestCnt TempdbRemapCnt AvgTempdbRemapTime
----------- ---------- ----------- ----------- ----------- ----------- ------------------------------- -------------- ----------- ------------- ------------- ------------ -------------- ------------ ------------------------------ -------------------------------- ------------------------------ ------------------------------ ----------- -------------- ------------------
107558527 0 1 2 81900 14 Feb 28 2014 11:03AM 6 16 21228 0 1366 0 0 *ss0107558527_2003073569ss* stored procedure NULL tempdb 40 0 0
107558527 0 1 2 81896 14 Feb 28 2014 11:00AM 14 5 219665 0 158 0 0 *ss0107558527_2003073569ss* stored procedure NULL tempdb 66 0 0
(2 rows affected)
Read the other plan:-
10:1> select show_cached_plan_in_xml (107558527,81900,6)
10:2> go
<snip>
(running select show_cached_plan_in_xml (107558527,0,6) will display all plans btw)
Now print the other plan (tablescan on notblocky):
11:1> dbcc prsqlcache (107558527,1)
11:2> go
QUERY PLAN FOR STATEMENT 1 (at line 1).
STEP 1
The type of query is DBCC.
SSQL_DESC 0x0x3078ad130
ssql_name *ss0107558527_2003073569ss*
ssql_hashkey 0x0x77647a21 ssql_id 107558527
ssql_suid 1 ssql_uid 1 ssql_dbid 2 ssql_spid 0
ssql_status 0x0xa0 ssql_parallel_deg 1
ssql_isolate 1 ssql_tranmode 32
ssql_keep 0 ssql_usecnt 20 ssql_pgcount 14
ssql_optgoal allrows_oltp ssql_optlevel ase_current
opt options bitmap 00809f172c61f5ffff7f37ffdfff7f870300000000000000000000000000
SQL TEXT: select * from blocky, notblocky where blocky.b1=notblocky.b1
QUERY PLAN FOR STATEMENT 1 (at line 1).
Optimized using Serial Mode
STEP 1
The type of query is SELECT.
3 operator(s) under root
|ROOT:EMIT Operator (VA = 3)
|
| |NESTED LOOP JOIN Operator (VA = 2) (Join Type: Inner Join)
| |
| | |SCAN Operator (VA = 0)
| | | FROM TABLE
| | | blocky
| | | Index : ix
| | | Forward Scan.
| | | Positioning at index start.
| | | Index contains all needed columns. Base table will not be read.
| | | Using I/O Size 2 Kbytes for index leaf pages.
| | | With LRUBuffer Replacement Strategy for index leaf pages.
| |
| | |SCAN Operator (VA = 1)
| | | FROM TABLE
| | | notblocky
| | | Table Scan.
| | | Forward Scan.
| | | Positioning at start of table.
| | | Using I/O Size 2 Kbytes for data pages.
| | | With LRU Buffer Replacement Strategy for data pages.
Run the query again and it is now using the alternate plan:
12:1> select * from blocky, notblocky where blocky.b1=notblocky.b1
12:2> go
QUERY PLAN FOR STATEMENT 1 (at line 1).
STEP 1
The type of query is EXECUTE.
Executing a previously cached statement (SSQL_ID = 107558527).
QUERY PLAN FOR STATEMENT 1 (at line 1).
Optimized using Serial Mode
STEP 1
The type of query is SELECT.
3 operator(s) under root
|ROOT:EMIT Operator (VA = 3)
|
| |NESTED LOOP JOIN Operator (VA = 2) (Join Type: Inner Join)
| |
| | |SCAN Operator (VA = 0)
| | | FROM TABLE
| | | blocky
| | | Index : ix
| | | Forward Scan.
| | | Positioning at index start.
| | | Index contains all needed columns. Base table will not be read.
| | | Using I/O Size 2 Kbytes for index leaf pages.
| | | With LRU Buffer Replacement Strategy for index leaf pages.
| |
| | |SCAN Operator (VA = 1)
| | | FROM TABLE
| | | notblocky
| | | Table Scan.
| | | Forward Scan.
| | | Positioning at start of table.
| | | Using I/O Size 2 Kbytes for data pages.
| | | With LRU Buffer Replacement Strategy for data pages.
So if using dbcc prsqlcache to look at statement cache plans, always check to see if you have more than one plan in monCachedProcedures for it, if you do you can use the above method to iterate through each one and if necessary test the sql against each one.