In this post, originally written by Glenn Paulley and posted to sybase.com in November of 2009, Glenn talks about the undocumented 9.0.2 feature called ‘”og expensive queries”, which could be used in version 188.8.131.5213 and later to help diagnose performance issues related to specific queries.
In SQL Anywhere Version 10 we introduced Application Profiling, a set of graphical tools that could not only assist DBAs to diagnose performance problems but could also recommend solutions to common performance problems discovered during the analysis. Included in Application Profiling is a (cheap) mechanism to capture queries (and their access plans) that consume a significant proportion of server resources or whose elapsed time exceeds a certain threshold.
But, you say – you’re still running SQL Anywhere Version 9.0.2. Now what?
If, after preliminary problem determination, you believe you are experiencing a performance problem due to a suboptimal access plan for a specific SQL query, a diagnostic feature slipstreamed into 9.0.2 build 3113 may be useful. The feature is termed “log expensive queries” and it provides a means to log SQL statement and/or their graphical plans in a SQL Anywhere request-level log.
Log Expensive Queries
The “log expensive queries” feature permits the server to dump the SQL text or graphical plans of expensive queries to the request level log. A new server command line option, -zx [cost], turns the feature on and defines the threshold above which queries are considered “expensive”. Expensive queries can be handled in two ways: when the -zp option is also specified, detailed graphical plans will also appear in the request-level log. Otherwise, only the SQL text of the expensive queries will be logged.
When both -zx (LogExpensiveQueries) and -zp (RememberLastPlan) are set:
- queries whose estimated cost is greater than [cost] milliseconds will be built with full statistics-gathering gear, and a graphical plan will be dumped to the request-level log at build time;
- queries whose estimated cost is less than [cost] milliseconds will be built with low-detail statistics gathering gear;
- queries whose actual run-time is greater than [cost] milliseconds will have their graphical plan dumped to the request-level log when their cursor is closed. Plans will contain whatever level of statistical detail was determined for them at optimization time (as described in the first bullet point above).
When only the -zx command line switch is specified:
- query plans will be constructed with low-detail statistics gathering gear.
- queries whose actual run-time is greater than [cost] milliseconds will have their SQL text dumped to the request-level log when their cursor is closed.
The request-level log must be directed to a file for these outputs to appear – this is accomplished by using the -zo command line option or setting the RequestLogFile property. However, both SQL text and graphical plans will still appear even if the RequestLogging property is ‘None’.
Access plans appear as a single PLAN line in the request-level log; SQL text appears as a single INFO line. They are prefixed by a header that indicates whether they were dumped at build time or cursor completion time, and what the associated cost at that time was. Plans dumped at build time are prefixed by [XB [cost]], plans dumped at cursor completion time are prefixed by [XC [cost]], and SQL text dumped at completion time is prefixed by [XS [cost]] (where all costs are given in seconds, the same as displayed in graphical plans).
The LogExpensiveQueries property can be set by the -zx [cost] command line option, or by setting the LogExpensiveQueries server option with sa_server_option(), permitting the logging of expensive queries to occur on-the-fly.