[MDEV-6430] It is impossible to see if "filesort with small limit" optimization was used Created: 2014-07-08  Updated: 2014-07-09  Resolved: 2014-07-09

Status: Closed
Project: MariaDB Server
Component/s: None
Affects Version/s: 10.0.12
Fix Version/s: 10.0.13

Type: Bug Priority: Major
Reporter: Sergei Petrunia Assignee: Sergei Petrunia
Resolution: Fixed Votes: 0
Labels: None


 Description   

We've ported "filesort with small limit" optimization from mysql-5.6 into MariaDB 10.0.

The problem is, it is impossible to see whether that optimization is used or not.

In MySQL, one can check this as follows

  • set optimizer_trace=1
  • SELECT // need to run SELECT, not EXPLAIN
  • select * from optimizer_trace

And then look for something like this:

      "join_execution": {
 
...
 
            "filesort_priority_queue_optimization": {
 
              "limit": 10,
 
              "rows_estimate": 198717,
 
              "row_size": 215,
 
              "memory_available": 262144,
 
              "chosen": true
 
            },

In MariaDB, there is no optimizer_trace, so one can't see it at all.

 Comments   
Comment by Sergei Petrunia [ 2014-07-08 ]

It would be logical if the output was reflected in EXPLAIN. The problem is that both MySQL and MariaDB make the decision about whether to use PQ at a very late phase:

  #0  check_if_pq_applicable (param=0x7ffff7e9fb50, filesort_info=0x7ffff7e9fbd0, table=0x7fffe3cabe70, num_rows=216437, memory_available=2097152) at /home/psergey/dev2/10.0/sql/filesort.cc:1307
 
  #1  0x000000000084db80 in filesort (thd=0x7fffd4398070, table=0x7fffe3cabe70, sortorder=0x7fffe3c948a8, s_length=1, select=0x7fffe3c943b0, max_rows=10, sort_positions=false, examined_rows=0x7ffff7ea0100, found_rows=0x7ffff7ea0108) at /home/psergey/dev2/10.0/sql/filesort.cc:224
 
  #2  0x00000000006c46aa in create_sort_index (thd=0x7fffd4398070, join=0x7fffe3c78a98, order=0x7fffe3c78988, filesort_limit=10, select_limit=10, is_order_by=true) at /home/psergey/dev2/10.0/sql/sql_select.cc:20571
 
  #3  0x0000000000699c40 in JOIN::exec_inner (this=0x7fffe3c78a98) at /home/psergey/dev2/10.0/sql/sql_select.cc:3046
 
  #4  0x0000000000697142 in JOIN::exec (this=0x7fffe3c78a98) at /home/psergey/dev2/10.0/sql/sql_select.cc:2366
 
  #5  0x000000000069a715 in mysql_select (thd=0x7fffd4398070, rref_pointer_array=0x7fffd439c6d8, tables=0x7fffe3c78290, wild_num=1, fields=..., conds=0x0, og_num=1, order=0x7fffe3c78988, group=0x0, having=0x0, proc_param=0x0, select_options=2147748608, result=0x7fffe3c78a78, unit=0x7fffd439bd78, select_lex=0x7fffd439c460) at /home/psergey/dev2/10.0/sql/sql_select.cc:3303

EXPLAIN execution does not go through filesort()/check_if_pq_applicable(). In order to check whether we're using PQ in EXPLAIN, one would need to do some code re-structuring.

Comment by Sergei Petrunia [ 2014-07-08 ]

Status variables do not have a counter for PQ-based sorting:

MariaDB [j61]> show status like '%sort%';
 
+-------------------+-------+
 
| Variable_name     | Value |
 
+-------------------+-------+
 
| Sort_merge_passes | 0     |
 
| Sort_range        | 0     |
 
| Sort_rows         | 10000 |
 
| Sort_scan         | 1     |
 
+-------------------+-------+
 
4 rows in set (0.00 sec)

Comment by Sergei Petrunia [ 2014-07-08 ]

Slow query log entry (with log_slow_verbosity=query_plan,explain):

# Time: 140708 18:50:08
 
# User@Host: root[root] @ localhost []
 
# Thread_id: 3  Schema: j61  QC_hit: No
 
# Query_time: 4.110269  Lock_time: 0.004791  Rows_sent: 10  Rows_examined: 100010
 
# Full_scan: Yes  Full_join: No  Tmp_table: No  Tmp_table_on_disk: No
 
# Filesort: Yes  Filesort_on_disk: No  Merge_passes: 0
 
#
 
# explain: id   select_type     table   type    possible_keys   key     key_len ref     rows    Extra
 
# explain: 1    SIMPLE  t5      ALL     NULL    NULL    NULL    NULL    98496   Using filesort
 
#
 
use j61;
 
SET timestamp=1404831008;
 
select * from t5  order by a limit 10;

" Filesort: Yes " comes from "log_slow_verbosity=explain", which originally comes from "extended statistics in the slow query log" from Percona Server. It may be natural to extend it to show whether PQ-based sorting was used.

Comment by Sergei Petrunia [ 2014-07-09 ]

Decisions after discussion: will both add a status counter and a slow query log entry.

Slow query log entries will look like this:

# Filesort: Yes  Filesort_on_disk: No  Merge_passes: 0  Priority_queue: Yes|No

pt-query-digest is able to parse this.

Status variable name will be:

Sort_priority_queue_sorts

Generated at Thu Feb 08 07:11:50 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.