SHOW ANALYZE
Contents
Syntax
SHOW ANALYZE [FORMAT=JSON] FOR <connection_id>;
Description
SHOW ANALYZE
allows to get ANALYZE-like output of a currently running statement: the command
SHOW ANALYZE [FORMAT=JSON] FOR <connection_id>;
connects to the query running in connection connection_id
, gets information about the query plan it is executing, also gets information about the runtime statistics of the execution so far and returns it in a format similar to ANALYZE [FORMAT=JSON]
output.
This is similar to SHOW EXPLAIN command, the difference is that SHOW ANALYZE
also produces runtime statistics information.
Intended usage
Imagine you're trying to troubleshoot a query that never finishes. Since it doesn't finish, it is not possible to get ANALYZE output for it. With SHOW ANALYZE
, you can get the runtime statistics without waiting for the query to finish.
Example 1: Row counts
Consider tables orders
and customer
and a join query finding total amount of orders from customer with Gold status:
explain format=json select sum(orders.amount) from customer join orders on customer.cust_id=orders.cust_id where customer.status='GOLD';
EXPLAIN for this query looks like this:
+------+-------------+----------+------+---------------+---------+---------+------------------+--------+-------------+ | id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra | +------+-------------+----------+------+---------------+---------+---------+------------------+--------+-------------+ | 1 | SIMPLE | customer | ALL | PRIMARY | NULL | NULL | NULL | 199786 | Using where | | 1 | SIMPLE | orders | ref | cust_id | cust_id | 5 | customer.cust_id | 1 | | +------+-------------+----------+------+---------------+---------+---------+------------------+--------+-------------+
We run the SELECT and it has been running for 30 seconds.
Let's try SHOW ANALYZE
:
MariaDB [test]> show analyze format=json for 3; | { "r_query_time_in_progress_ms": 32138,
^ this shows how long the query has been running.
"query_block": { "select_id": 1, "r_loops": 1, "nested_loop": [ { "table": { "table_name": "customer", "access_type": "ALL", "possible_keys": ["PRIMARY"], "r_loops": 1, "rows": 199786, "r_rows": 110544,
^ rows
shows the number of rows expected. r_rows
in this example shows how many rows were processed so far (110K out of expected 200K). r_loops
above shows we're doing the first table scan (which is obvious for this query plan).
"filtered": 100, "r_filtered": 9.538283398, "attached_condition": "customer.`status` = 'GOLD'" } }, { "table": { "table_name": "orders", "access_type": "ref", "possible_keys": ["cust_id"], "key": "cust_id", "key_length": "5", "used_key_parts": ["cust_id"], "ref": ["test.customer.cust_id"], "r_loops": 10544, "rows": 1, "r_rows": 99.99222307,
^ here, rows: 1
shows the optimizer was expecting 1 order per customer. But r_rows: 99.9
shows that execution has found on average 100 orders per customer. This may be the reason the query is slower than expected!
The final chunk of the output doesn't have anything interesting but here it is:
"filtered": 100, "r_filtered": 100 } } ] } }
Example 2: Timing information
Regular SELECT queries collect row count information, so SHOW ANALYZE
can display it. However, detailed timing information is not collected, as collecting it may have CPU overhead. But if the target query is collecting timing information, SHOW ANALYZE
will display it. How does one get the target query to collect timing information? Currently there is one way: if the target is running ANALYZE
, it IS collecting timing information.
Re-running the previous example:
Connection 1> ANALYZE SELECT ... ;
Connection 2> SHOW ANALYZE FORMAT=JSON FOR <connection_id>; ANALYZE { "r_query_time_in_progress_ms": 30727, "query_block": { "select_id": 1, "r_loops": 1, "nested_loop": [ { "table": { "table_name": "customer", "access_type": "ALL", "possible_keys": ["PRIMARY"], "r_loops": 1, "rows": 199786, "r_rows": 109994, "r_table_time_ms": 232.699, "r_other_time_ms": 46.355,
^ Ok, so far, out of 30 seconds, only 232 millisecond were spent in reading table customer. The bottleneck is elsewhere...
"filtered": 100, "r_filtered": 9.085950143, "attached_condition": "customer.`status` = 'GOLD'" } }, { "table": { "table_name": "orders", "access_type": "ref", "possible_keys": ["cust_id"], "key": "cust_id", "key_length": "5", "used_key_parts": ["cust_id"], "ref": ["test.customer.cust_id"], "r_loops": 9994, "rows": 1, "r_rows": 99.99779868, "r_table_time_ms": 29460.609, "r_other_time_ms": 986.842,
29.4 seconds were spent reading table orders (and 0.986 seconds in processing the obtained rows). Now we can see where the query is spending time.
"filtered": 100, "r_filtered": 100 } } ] } }