Review input: https://lists.launchpad.net/maria-developers/msg13078.html .

The tabular form is basically done, need to do the FORMAT=JSON part.

Trying the FORMAT=JSON on a test query: https://gist.github.com/spetrunia/69fb0c48b3b5412a546575f02d3b3de7

Ok this gives some clue about query execution. Things that I would like to see but do not see

• a clear indication that this is a SHOW ANALYZE output, that is, it describes a run in progress. (reasoning: we expect to get it from users/customers/etc. need to minimize the effects of getting the wrong file and other kinds of "broken telephone" effect).

• how much time the query has spent running (this is needed to relate it with other r_*time_ms values).

A select is in its first execution looks like so:

          "query_block": {

            "select_id": 2,

            "operation": "UNION",

            "r_loops": 1,

            "r_total_time_ms": 0,

compare to select that has never been executed:

          "query_block": {

            "select_id": 3,

            "nested_loop": [

...

1. How would you like to see the clear indication?

• SHOW ANALYZE: {
• SHOW ANALYZE (running query): {
• any other?

2. How to name this field and where to place it? Is it OK to place it in the top of the output like this:
SHOW ANALYZE: {
"r_query_running_time_ms": 5432
"query_block": {
"select_id": 1,
...

oleg.smirnov, good questions.. I'm still trying to figure out answer for these...

Looking at a query that does filesort first, and then join with the second table:
https://gist.github.com/spetrunia/cb8c73f62d733a771697aade575a54c0

(diff'ing first SHOW ANALYZE output against the second)

Here's an example : https://gist.github.com/spetrunia/664a80db9110b02e0a91642e8aa987df
The target runs a regular SELECT - the execution is not timed.
However, the output has r_total_time_ms members:

          "query_block": {

            "select_id": 2,

            "r_loops": 731,

            "r_total_time_ms": 0,

I'm not sure if we should call this incorrect, but looking at it as a user, it doesn't look very intuitive...

Indeed, r_total_time_ms shows up due to this logic in Explain_select::print_explain_json:

    if (is_analyze && time_tracker.get_loops())

    {

      writer->add_member("r_loops").add_ll(time_tracker.get_loops());

      writer->add_member("r_total_time_ms").add_double(time_tracker.get_time_ms());

    }

The code assumes that is_analyze=true means that there is timing information.

The first idea off the top of the head: check if time_tracker.cycles==0 (wrap this into a call like time_tracker.have_timings()) and don't print r_*time_ms in this case.

2. How to name this field and where to place it? Is it OK to place it in the top of the output like this:
SHOW ANALYZE: {
"r_query_running_time_ms": 5432
"query_block": {

As agreed on Slack: Let it be r_time_in_progress_ms at the top level. For non-ANALYZE execution, there's a question of where to get the query start time. Please check where INFORMATION_SCHEMA.PROCESSLIST gets it from.

Pushed a new commit addressing the issues discussed.

{{commit a335245bbf9c49327d8b34ac30e3ad49822a5aa3 (HEAD > bb-10.8MDEV-10000, origin/bb-10.8-MDEV-10000)
Author: Oleg Smirnov <olernov@gmail.com>
Date: Wed Feb 16 13:03:46 2022 +0700

MDEV-27021 Add explicit indication of SHOW EXPLAIN/ANALYZE.

1. Add explicit indication that the output is produced by
SHOW EXPLAIN/ANALYZE FORMAT=JSON command.
2. Remove useless "r_total_time_ms" field from SHOW ANALYZE FORMAT=JSON
output when there is no timed statistics gathered.
3. Add "r_query_time_in_progress_ms" to the output of SHOW ANALYZE FORMAT=JSON.
}}

psergei, please review.

By the way, I haven't fixed test cases yet, so some tests will fail. Once we're happy with the results I'll fix the test cases accordingly.

The last patch is ok. I've requested small fix in comments. After that, we can pass it to testing.

Hey
Nice to see this being implemented!

Here's a related post:

"extend explain output to include "attached_condition""
https://jira.mariadb.org/browse/MDEV-27146

Thanks!