Shoot me an email to get a pdf of this article...
Finding slow running queries in ASE 15
Introduction
Fixing a performance problem isn’t usually difficult, once you’ve found it.
According to studies, 80% of the mean time to resolution in performance is the identification of the root cause. When you consider that other studies have shown that 24% of IT staff time is devoted to performance issues, the math becomes very simple: eliminate 80% of the 24% and you get back 20% of your staff time.
There are several different places you have to look when you’re evaluating a performance problem. First, you have to verify that the problem is within the database / database server. In today’s multi-tier environments, this can be nontrivial. There is at least one good tool out on the market that will identify which tier is actually responsible for the most elapsed time, but for purposes of this article, we’ll assume you’re positively identified issues in the data tier. (Drop me an email for my personal take on application performance monitoring tools!)
If you are fortunate enough to know which queries are problems, most of the time you’ll use “set showplan” output to analyze the query, find out which index it is or isn’t using, and act accordingly. Analyzing showplan output is beyond scope of this article (it would make a good series, though), but as with each new ASE release, ASE 15 showplan output has gotten yet easier to read (and if you like, you can even get it on xml format for later storage and parsing).
In environments though of even light-to-moderate complexity, sometimes all you know is that users are complaining of general slowness. In the past, it has been nontrivial to identify specifically what was slowing the users (or the system) down. Is it a single specific query? Is there one query which is blocking a class of users? A query which is running in 1.2 seconds, which perhaps doesn’t register high enough on the pain scale to rate a complaint call, but which is running thousands of times per minute (or second!) and is using 43% of resources? If it’s specific user(s), what are they doing?
If you are responsible for tuning, you’ll first try to isolate the target query. Prior to doing this, though, you may want to start at a high level, look at sp_sysmon output to make sure it’s not a system issue, and then try to track down overall problem queries.
With the advent of mid-12.5.x, and enhance in ASE 15, Sybase introduced the MDA tables, which after a relatively simple install, enables the DBA to identify what queries are running, what they’re doing, what is holding them up / speeding them up, This has been an amazing advancement over prior tuning work.
In addition, for ASE 15, Sybase has introduced the ability to collect query metrics, which enables you to track queries and query performance for your session, and if you have the sa_role, for another login’s session.
Identify the problem – solve the problem – verify the solution. This will make friends fast.
Identifying problem queries
The first step in solving a problem is identifying the root cause. Sometimes your mission is vague: Everything seems slow today. You might start looking at sp_sysmon output (WAY beyond scope, but check out the Administration Guide or pick up “Administering ASE 15” from Wordware publishing for detail). The sp_sysmon output will validate the environment at the macro scale (i.e. no server-wide bottlenecks at CPU, IO, Network, Memory / Cache, etc.). The next step is to find the problem queries.
At that point, you may have specific information: “The order entry application is slow.” If you are very lucky, you’ve got only a few screens to look at, a few developers to interview regarding what SQL or which stored procedures are associated with the screens, and specific sets of queries to look at.
On other occasions, you hear, “Most of what I’m working on is slow,” and if you inquire further, you hear, “I think I was working in…” and wonder if you’re going to find the root of the problem.
ASE 15 now offers solutions to each problem: When you don’t know where the problem is, you can use the MDA tables to find out what’s taking up the time on your server. When you know which login is causing the problem, you can use query metrics to find out what the login is doing. And, once you’ve identified the problem queries, you can use the updated showplan to identify what the server is using as a query plan.
MDA tables
The Monitoring and Data Access (MDA) tables were added in ASE 12.5.0.3 to help identify what system resources are being used for. They are virtual tables in the master database. There was an install process which required, as well as a bit of configuration required before they would be usable.
Monitoring has turned out to be so important that with ASE 15 the MDA tables are installed as part of the buildmaster script (i.e. at installation time).
The MDA tables enable you to identify what queries are running, what resources they are taking up, and what the queries are waiting for (for example, network, io, or locks to be released).
The complete list of MDA tables in 15.0.2 follows {tech writer please format these so as to not take up too much of this document}:
monCachePool
monIOQueue
monProcedureCacheModuleUsage
monCachedObject
monLicense
monProcess
monCachedProcedures
monLocks
monProcessActivity
monCachedStatement
monNetworkIO
monProcessLookup
monDataCache
monOpenDatabases
monProcessNetIO
monDeadLock
monOpenObjectActivity
monProcessObject
monDeviceIO
monOpenPartitionActivity
monProcessProcedures
monEngine
monProcedureCache
monProcessSQLText
monErrorLog
monProcedureCacheMemoryUsage
monProcessStatement
monProcessWaits
monTableColumns
monProcessWorkerThread
monTableParameters
monState
monTables
monStatementCache
monWaitClassInfo
monSysPlanText
monWaitEventInfo
monSysSQLText
monSysStatement
monSysWaits
monSysWorkerThread
There are other, more exhaustive, dissertations available on the Sybase web site and across the internet on using these, but here are a few quick and easy things you can do with them. If you have trouble accessing the MDA tables, ask your DBA too add the “mon_role” to your login.
MDA tables at the application level
Two tables in particular will help identify the SQL running in the application: monProcessSQLText and monSysSQLText.
monProcessSQLText
shows currently executing SQL
monSysSQLText
shows recent, completed SQL
monSysStatement
More information on completed SQL statements
Let’s say access to a particular table is slow; what SQL accesses the table?
select * into #sqltext from monSysSQLText
select * from #sqltext where SQLText like ‘%pt_sample%’
/* Note: after you’ve selected the data once, ASE assumes that you don’t want to see it again. A second select from the same table will get you successive data. If you want to access it again later, you may want to select into a temp table… and, this is good information to keep historically*/
{tech writer, please format the following for readability, replacing commas with tabs, thank you!}
SPID,KPID,ServerUserID,BatchID,SequenceInBatch,SQLText
26,1900573,1,27,1,'select * from pt_sample s, pt_tx t where t.id = s.id'
And, now how about some statistics on the statement?
select * from monSysStatement where KPID = 1900573
SPID,KPID,DBID,ProcedureID,PlanID,BatchID,ContextID,LineNumber,CpuTime,WaitTime,MemUsageKB,PhysicalReads,LogicalReads,PagesModified,PacketsSent,PacketsReceived,NetworkPacketSize,PlansAltered,RowsAffected,ErrorStatus,HashKey,SsqlId,StartTime,EndTime
25, 1900573,1,1280004560,30,12,2,0,0,0,684,0,0,0,0,0,2048,0,0,0,0,0,2008-11-15 10:03:14.793,2008-11-15 10:03:14.793
You can see:
· Number of logical I/Os
· Number of physical I/Os
· Number of network packets sent/received
· Number of milliseconds of ‘waiting time’ during statement execution
· Start time & end time of execution
There’s a wealth of other information you can glean from the MDA tables including unused indexes, table utilization, physical io, table activity, heavily utilized tables, and wait states (indicating what applications are waiting for). This is worth taking the time to understand.
Tip: There is a configuration parameter, ‘max SQL text monitored’, which is STATIC, which limits the size of the SQL statement that you can see (that is, it truncates past this limit). You should try 16384 as a value. This increases the amount of memory used by the server, but should give you the ability to look at your entire query most of the time.
Query Metrics
Query metrics allow you to measure performance for your session using the sp_metrics stored procedure. This allows you to track:
· Cpu execution time, elapsed time
· Logical I/O (found in cache, cached by async prefetch)
· Physical I/O (regular I/O, async prefetch)
· Count - # of times query executed
· Tracks min, max and avg (less count)
This is likely to replace the statistics io and statistics time session settings.
To capture metrics,
1) You need to enable the metrics capture at the server level:
sp_configure "enable metrics capture", 1 /* note that this defaults to zero */
2) you then need to enable metrics capture for your session
set metrics capture on
3) Then you’ll flush the metrics from the aggregation to the system view, sysquerymetrics using the sp_metrics stored procedure
sp_metrics ‘flush’
4) And finally, you can select from the sysquerymetrics table
select * from sysquerymetrics
Using sp_metrics
The sp_metrics stored procedure is used to collect and retain groups of captured session metric data.
sp_metrics [flush backup drop help], @arg1 [, @arg2]
Query metrics are captured in the default running group (the running group with a group id (gid) of 1) in the sysquerymetrics view. Note that the sysquerymetrics view contains a self join & decoding of the sysqueryplans table, which contains abstract query plan information (among other things).
sp_metrics has built-in help:
sp_metrics ‘help’ /* in case you forget syntax or the stored procedure arguments.*/
(Output: )
Command list:
help - get help on a command
flush - flush all metrics from memory to system tables
drop - drop a metric ID or a group of metrics
backup - move the metrics in the default group to a backup group
filter - delete metrics records based on filtering condition
show - display the number of records in each metrics group
You can move metrics to a different group using the “backup” parameter.
sp_metrics 'flush'
Flushes all metrics from memory to system tables. If you skip this step, the information you need may not yet be in the view
sp_metrics 'drop', '2', '5'
Drops the groups of saved metrics. @arg1 is an integer in char form representing the first metrics group to drop in the range (must be a valid group), @arg2 is an integer in char form representing the last metrics group to drop in the range
sp_metrics 'backup', '6'
Saves metrics for future perusal. This example moves the metrics in the default group (i.e. what is currently running) to group #6. @arg1 is an integer in char form representing group number. It must be higher than 1 (1 represents the current group)
Application tracing
You can trace all of the SQL text for an existing session to a physical file using the set tracefile session option. This is great for a situation when you are exploring complaint s from a specific user and want to find out what the user is doing. Use it like this:
Set tracefile FILENAME [for spid]
And disable it like this:
set tracefile off [for spid]For example,
Set tracefile ‘/opt/Sybase/tracefiles/2008 1101.trc12’ for 12
… will write all SQL for server process ID 12 to the file at path ‘/opt/Sybase/tracefiles/2008 1101.trc12’. If you don’t specify a spid, you will record SQL for your own session.
This will store SQL as well as query plans (showplan output), statistics (statistics io output), show_sqltext (below!), set option show, and/or dbcc traceon (100) output.
You must either have the sa or sso role in order to run “set tracefile”, or you must have been granted “set tracefile” permission. Note that the tracefile will be on the server machine, not on your client.
set show_sqltext
You can print the SQL text for ad-hoc queries, stored procedures, cursors, and dynamic prepared statements using set show_sqltext. You do not need to enable the set show_sqltext before you execute the query (as you do with commands like set showplan on) to collect diagnostic information for a SQL session. You can do it when you get the “things are running slow” telephone call.
Before you enable show_sqltext, you must first use dbcc (dbcc traceon(3604)) to instruct the server to send the output to your terminal instead of to standard output (i.e. to the console of the session that started up the ASE instance).
The syntax for set show_sqltext is:
set show_sqltext {on off}
For example, this enables show_sqltext:
set show_sqltext on
Once set show_sqltext is enabled, Adaptive Server prints all SQL text to standard out for each command or system procedure you enter. Depending on the command or system procedure you run, this output can be extensive. This is a good command to run in conjunction with the set tracefile option.
Summary
Every application encounters the occasional performance problem. (Some systems encounter problems more occasionally than others).
There are a variety of tools that have been around for a while (for example, sp_sysmon) which will enable you to understand server performance from a macro level. But, when it comes to identifying problem queries, or problem logins, it can be more difficult.
With the advent of ASE 12.5, Sybase introduced the MDA tables to identify all server activity. This has been enhanced with ASE 15. In addition, ASE 15 introduced a variety of ways to identify session metrics, SQL, and query plans to help identify issues as they crop up.
