Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-407

Print EXPLAIN [ANALYZE] in the slow query log

Details

    • Task
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Fixed
    • None
    • None
    • None

    Description

      SHOW EXPLAIN allows to produce EXPLAIN during the query execution. We are now able to save it in the slow query log.

      The user interface is as follows:

      "explain" is a new flag in log-slow-verbosity argument:

      [mysqld]
      		 
      ...
      		 
      log-slow-verbosity=query_plan,explain

      The output is printed into slow query log like this:

      # User@Host: root[root] @ localhost []
      		 
      # Thread_id: 2  Schema: j4  QC_hit: No
      		 
      # Query_time: 0.000629  Lock_time: 0.000202  Rows_sent: 3  Rows_examined: 3
      		 
      # Full_scan: Yes  Full_join: No  Tmp_table: No  Tmp_table_on_disk: No
      		 
      # Filesort: No  Filesort_on_disk: No  Merge_passes: 0
      		 
      ## <explain>
      		 
      ##   id select_type     table   type    possible_keys   key     key_len ref     rows    Extra
      		 
      ##   1  SIMPLE  t1      ALL     NULL    NULL    NULL    NULL    3       Using where
      		 
      ## </explain>
      		 
      SET timestamp=1381828772;
      		 
      select * from t1 where a between 1 and 3333;

      Attachments

        Issue Links

          is blocked by

          Task - A task that needs to be done. MDEV-3798 Add EXPLAIN for UPDATE/DELETE (mwl #51)

          • Major - Major loss of function.
          • Closed
          relates to

          Bug - A problem which impairs or prevents the functions of the product. MDEV-5045 Server crashes in QPF_query::print_explain with log_slow_verbosity='query_plan,explain'

          • Blocker - Blocks development and/or testing work, production could not run.
          • Closed

          Bug - A problem which impairs or prevents the functions of the product. MDEV-5060 Server crashes on EXPLAIN EXTENDED or EXPLAIN PARTITIONS with explain in slow_log

          • Major - Major loss of function.
          • Closed

          Bug - A problem which impairs or prevents the functions of the product. MDEV-5067 Valgrind warnings (Invalid read) in QPF_table_access::print_explain / String::append on a SELECT sq with DISTINCT

          • Major - Major loss of function.
          • Closed

          Bug - A problem which impairs or prevents the functions of the product. MDEV-5106 Server crashes in Explain_union::print_explain on ER_TOO_BIG_SELECT with explain in slow log

          • Major - Major loss of function.
          • Closed

          Bug - A problem which impairs or prevents the functions of the product. MDEV-5117 Explain for a query executed as a PS is not written into the slow log

          • Minor - Minor loss of function, or other problem where easy workaround is present.
          • Closed

          Bug - A problem which impairs or prevents the functions of the product. MDEV-5118 Explain output for SHOW EXPLAIN in the slow log looks useless

          • Trivial - Cosmetic problem like misspelt words or misaligned text.
          • Open

          Bug - A problem which impairs or prevents the functions of the product. MDEV-5125 Test sys_vars.log_slow_verbosity_basic fails on 10.0-base-explain-slowquerylog tree

          • Minor - Minor loss of function, or other problem where easy workaround is present.
          • Closed

          Task - A task that needs to be done. MDEV-6388 ANALYZE $stmt output in the slow query log

          • Major - Major loss of function.
          • Closed

          Task - A task that needs to be done. MDEV-406 ANALYZE $stmt

          • Major - Major loss of function.
          • Closed

          Activity

            Ascending order - Click to sort in descending order
            psergei Sergei Petrunia created issue -
            psergei Sergei Petrunia made changes -
            Field Original Value New Value
            psergei Sergei Petrunia made changes -
            psergei Sergei Petrunia made changes -
            Assignee Sergei Petrunia [ psergey ]
            psergei Sergei Petrunia added a comment -

            Stack trace of where currently "query plan" information is written into the query log:

            #0 MYSQL_QUERY_LOG::write
            #1 0x00000000008a87b9 in Log_to_file_event_handler::log_slow
            #2 0x00000000008a91c5 in LOGGER::slow_log_print
            #3 0x00000000008b4b9f in slow_log_print
            #4 0x00000000006168d9 in log_slow_statement
            #5 0x0000000000616594 in dispatch_command
            #6 0x000000000061460f in do_command

            psergei Sergei Petrunia added a comment - Stack trace of where currently "query plan" information is written into the query log: #0 MYSQL_QUERY_LOG::write #1 0x00000000008a87b9 in Log_to_file_event_handler::log_slow #2 0x00000000008a91c5 in LOGGER::slow_log_print #3 0x00000000008b4b9f in slow_log_print #4 0x00000000006168d9 in log_slow_statement #5 0x0000000000616594 in dispatch_command #6 0x000000000061460f in do_command
            psergei Sergei Petrunia made changes -
            Status Open [ 1 ] In Progress [ 3 ]
            psergei Sergei Petrunia added a comment -

            The first patch is at lp:~maria-captains/maria/10.0-base-explain-slowquerylog

            psergei Sergei Petrunia added a comment - The first patch is at lp:~maria-captains/maria/10.0-base-explain-slowquerylog
            psergei Sergei Petrunia added a comment -

            Currently, EXPLAIN is only printed into the slow query log file. If the slow query log is directed to the table ( --log-output=TABLE --slow-query-log), then the EXPLAIN is not captured. This is the same as with log-slow-verbosity=query_plan.

            psergei Sergei Petrunia added a comment - Currently, EXPLAIN is only printed into the slow query log file. If the slow query log is directed to the table ( --log-output=TABLE --slow-query-log), then the EXPLAIN is not captured. This is the same as with log-slow-verbosity=query_plan.
            psergei Sergei Petrunia made changes -
            Description SHOW EXPLAIN allows to produce EXPLAIN during the query execution. We are now able to save it in the slow query log. SHOW EXPLAIN allows to produce EXPLAIN during the query execution. We are now able to save it in the slow query log.

            The user interface is as follows:

            "explain" is a new flag in log-slow-verbosity argument:

            {noformat}
            [mysqld]
            ...
            log-slow-verbosity=query_plan,explain
            {noformat}

            The output is printed into slow query log like this:
            {noformat}
            # Time: 130920 9:38:04
            # User@Host: root[root] @ localhost []
            # Thread_id: 2 Schema: test QC_hit: No
            # Query_time: 0.002969 Lock_time: 0.000941 Rows_sent: 132 Rows_examined: 132
            # Full_scan: Yes Full_join: No Tmp_table: No Tmp_table_on_disk: No
            # Filesort: No Filesort_on_disk: No Merge_passes: 0
            #
            # id select_type table type possible_keys key key_len ref rows Extra
            # 1 SIMPLE t0 ALL NULL NULL NULL NULL 1000
            #
            use test;
            SET timestamp=1379655484;
            select * from t0 limit 132;
            {noformat}
            elenst Elena Stepanova made changes -
            elenst Elena Stepanova made changes -
            elenst Elena Stepanova made changes -
            elenst Elena Stepanova made changes -
            elenst Elena Stepanova made changes -
            elenst Elena Stepanova made changes -
            elenst Elena Stepanova made changes -
            psergei Sergei Petrunia made changes -
            Description SHOW EXPLAIN allows to produce EXPLAIN during the query execution. We are now able to save it in the slow query log.

            The user interface is as follows:

            "explain" is a new flag in log-slow-verbosity argument:

            {noformat}
            [mysqld]
            ...
            log-slow-verbosity=query_plan,explain
            {noformat}

            The output is printed into slow query log like this:
            {noformat}
            # Time: 130920 9:38:04
            # User@Host: root[root] @ localhost []
            # Thread_id: 2 Schema: test QC_hit: No
            # Query_time: 0.002969 Lock_time: 0.000941 Rows_sent: 132 Rows_examined: 132
            # Full_scan: Yes Full_join: No Tmp_table: No Tmp_table_on_disk: No
            # Filesort: No Filesort_on_disk: No Merge_passes: 0
            #
            # id select_type table type possible_keys key key_len ref rows Extra
            # 1 SIMPLE t0 ALL NULL NULL NULL NULL 1000
            #
            use test;
            SET timestamp=1379655484;
            select * from t0 limit 132;
            {noformat}

            		 SHOW EXPLAIN allows to produce EXPLAIN during the query execution. We are now able to save it in the slow query log.

            The user interface is as follows:

            "explain" is a new flag in log-slow-verbosity argument:

            {noformat}
            [mysqld]
            ...
            log-slow-verbosity=query_plan,explain
            {noformat}

            The output is printed into slow query log like this:
            {noformat}
            # User@Host: root[root] @ localhost []
            # Thread_id: 2 Schema: j4 QC_hit: No
            # Query_time: 0.000629 Lock_time: 0.000202 Rows_sent: 3 Rows_examined: 3
            # Full_scan: Yes Full_join: No Tmp_table: No Tmp_table_on_disk: No
            # Filesort: No Filesort_on_disk: No Merge_passes: 0
            ## <explain>
            ## id select_type table type possible_keys key key_len ref rows Extra
            ## 1 SIMPLE t1 ALL NULL NULL NULL NULL 3 Using where
            ## </explain>
            SET timestamp=1381828772;
            select * from t1 where a between 1 and 3333;
            {noformat}
            psergei Sergei Petrunia added a comment -

            Changed formatting based on the input from the mailing list.

            psergei Sergei Petrunia added a comment - Changed formatting based on the input from the mailing list.
            psergei Sergei Petrunia added a comment -

            The code is in 10.0-base and 10.0 trees.

            psergei Sergei Petrunia added a comment - The code is in 10.0-base and 10.0 trees.
            psergei Sergei Petrunia made changes -
            Resolution Fixed [ 1 ]
            Status In Progress [ 3 ] Closed [ 6 ]
            serg Sergei Golubchik made changes -
            Workflow defaullt [ 12712 ] MariaDB v2 [ 44654 ]
            psergei Sergei Petrunia made changes -
            ratzpo Rasmus Johansson (Inactive) made changes -
            Workflow MariaDB v2 [ 44654 ] MariaDB v3 [ 64019 ]
            serg Sergei Golubchik made changes -
            Workflow MariaDB v3 [ 64019 ] MariaDB v4 [ 131953 ]

            People

              psergei Sergei Petrunia
              psergei Sergei Petrunia
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Git Integration

                  Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.