|
Sometimes we see huge difference between totals collected by ASA Profiler and analysis of ASA request log via stored procedure sa_get_request_profile. We capture data for all connections without any filters. Our application is written on PowerBuilder v12 and used ODBC. For example please see picture:
Returned result set is not huge : 10-20 rows. |
Profiler gets 213 msecs for 29 invocations of procedure sp_claim_d_claim_main, while Request Log shows 383564 (!) msecs for same executions.
|
See: http://dcx.sybase.com/index.html#sa160/en/dbusage/performance-s-5753386.html There are separate steps taken by the database when executing a query. (Note: The following answer is responding with the assumption that the software is minimally SQL Anywhere 10 and that you are using the new diagnostic profiling tools. I unfortunately don't readily have the definition of the system tables for ASA 9's 'tracing' capabilities and a query to get back the same results. However, I believe the explanation of the behaviour remains the same). The Application Profiling / Diagnostic Tracing 'Summary Tab' examines how long a statement took to execute/materialize inside the database server / optimizer (PREPARE / DESCRIBE / OPEN). The The same cursor results are also stored in the Application Profiling / Diagnostic Tracing tables, although I don't believe these times are displayed readily in the Sybase Central view. Here's a sample SQL query against the diagnostic tracing data tables to get at the 'cursor result' timings, and should be similar times to what you see in select top 10 sdr.connection_number, sdr.request_id, sdc.cursor_id, sdc.total_fetch_time_ms, sdr.start_time, sdr.finish_time, sdr.duration_ms from sa_diagnostic_cursor sdc, sa_diagnostic_request sdr where sdr.cursor_id = sdc.cursor_id order by sdc.total_fetch_time_ms desc; I believe that Ilia63 is comparing the execution profiler with request level logging. The execution profiler has been around a long time (and still is), and is not to be confused with application profiling or database tracing (although such confusion is natural given the new Sybase Central dialog design).
(28 Mar '13, 18:07)
Breck Carter
Replies hidden
Thanks. But is there a possibility to analyze the RL-file to get "how long a statement took to execute/materialize inside the database server"? For example, using a tracetime.pl-script (or a similar script)?
(29 Mar '13, 07:43)
Ilia63
1
AFAIK request level logging in Version 9 was limited to measuring and recording requests at the client-server boundary and had no ability to peer inside the server and look at what's going on. In particular, if the client application called a stored procedure, only the request and (eventual) response is recorded, which may very well account for the difference you are seeing; i.e., there is a LOT of client-server interface activity required to get a result set back to the application, above and beyond the actual procedure call down inside the server. The execution profiler, on the other hand, doesn't care about the client side, it only looks at what's going on inside, which probably accounts for the huge difference (I think Jeff is saying the same thing, albeit in perhaps a different context). You can take away this fact: Any processing you can push down into the server, if it reduces the client-server traffic, will benefit performance; see http://sqlanywhere.blogspot.ca/2011/07/thursday-quote-michael-stonebraker.html FWIW request-level logging in SQL Anywhere 10 (and 11 and 12 and 16) is much more powerful. It has the ability to peer inside; see http://dcx.sybase.com/index.html#sa160/en/dbadmin/zr-database-dbengine.html
(29 Mar '13, 09:32)
Breck Carter
If connection parameter LCLOSE=NO, then P.S. LazyClose (LCLOSE) connection parameter:
(23 Apr '13, 03:16)
Ilia63
|
