Examples of Using Query Profiling Information
These examples of using query profiling views use the DBT-3 schema and dataset of size 1 GB. Let us run the following simple query:
SELECT r_name FROM region WHERE r_name LIKE 'A%'\g
Executing . . .
+-------------------------+
|r_name |
+-------------------------+
|AFRICA |
|AMERICA |
|ASIA |
+-------------------------+
(3 rows in 0.034527 secs)
We can now see that this query appeared in the "iivwquery" view:
SELECT query_id, start_time, execution_time FROM iivwquery\g
Executing . . .
+-------------+-------------------------------------------------+--------------+
|query_id |start_time |execution_time|
+-------------+-------------------------------------------------+--------------+
| 29|2012-12-12 05:18:45.480209 | 0.000833|
+-------------+-------------------------------------------------+--------------+
(1 row in 0.003182 secs)
In this view, we see queries from the current session only. Queries can be identified, for example, by the "start_time" attribute. We see that this query has an ID of "29".
We can now select the profiling information for this query:
SELECT query_id, op_id, name, ticks, tuples, himem FROM iivwprof WHERE query_id = 29\g
Executing . . .
+-------------+------------+--------------------+---------------+---------------+---------------+
|query_id |op_id |name |ticks |tuples |himem |
+-------------+------------+--------------------+---------------+---------------+---------------+
| 29| 1| MScan(region) | 181224| 5| 146439|
| 29| 2| Select | 6091| 3| 16271|
| 29| 3|Project | 1542| 3| 16271|
+-------------+------------+--------------------+---------------+---------------+---------------+
(3 rows in 0.035141 secs)
We see that three Operators are used by this query. The "MScan(region)" operator (with op_id 1) scanned the "region" table and produced 5 "tuples", as this table contains 5 records. The Select operator selected records matching our selection filter, producing 3 tuples. Finally, the Project operator was used to format the end result.
Looking at the "ticks," we see that Project and Select consume extremely little time (keep in mind that 1 tick on a 2 GHz machine is only 0.5 nanosecond). The MScan operator uses slightly more, as it needs to perform more complex actions, such as checking if the data is in memory and decompressing it. Similarly, the memory usage is trivial for Project and Select, and slightly higher for MScan.
For a more complex example, let’s run this query:
SELECT COUNT(*) FROM lineitem JOIN orders ON l_orderkey = o_orderkey WITH MAX_PARALLEL 1\g
Executing . . .
+----------------------+
|col1 |
+----------------------+
| 6001215|
+----------------------+
(1 row in 0.764545 secs)
After looking up the query_id for this query (as shown in the previous example), we can see the profiling information for this query by running:
SELECT query_id, op_id, name, ticks, tuples, himem FROM iivwprof WHERE query_id = 31\g
Executing . . .
+-------------+------------+--------------------+---------------+---------------+---------------+
|query_id |op_id |name |ticks |tuples |himem |
+-------------+------------+--------------------+---------------+---------------+---------------+
| 31| 1| Scan(lineitem| 121779356| 6001215| 113897|
| 31| 2| MScan(orders) | 34302310| 1500000| 113897|
| 31| 3| HashJoinN | 1847879241| 6001215| 60045807|
| 31| 4| Aggr(DENSE) | 4883348| 1| 196156|
| 31| 5| Project | 46154| 1| 16271|
| 31| 6| As(IISAGG2_0) | 1079| 1| 16271|
| 31| 7| Reuse | 7377| 0| 16271|
| 31| 8|Project | 3019| 1| 16271|
+-------------+------------+--------------------+---------------+---------------+---------------+
(8 rows in 0.002574 secs)
We focus on operators 1 through 4. (Operators 5 through 8 are "management" operations, which we will ignore here.) There are two MScan operators scanning the "lineitem" and "order" tables and producing respectively 6 million and 1.5 million tuples. These tables are combined in the HashJoinN operator, responsible for performing the JOIN construct in SQL. To perform that operation, a significant amount of memory is used—about 60 MB. This operator also consumes the majority of the query time. See that the output count of the HashJoinN operator matches the count of the "lineitem" table, because every tuple matches something in the "order" table. Finally, the count of the join result is counted in the Aggr operator.