Hi Aleksey,

Would it be possible to provide a dump of the database (preferably with data, but if it's strictly confidential, at least the table structures)?
You can upload it to the private section of our ftp server ftp://ftp.askmonty.org/private , so nobody except for MariaDB developers would have access to it.

Please also attach output of SHOW VARIABLES from the session where you observe the described problem.

Thank you.

As expected, the problem is not reproducible on empty tables. I will try to generate some artificial data, but it will take some time since there are many tables participating in the query, and they have join conditions so the data cannot be purely random.

Aleksey,

The whole procedure in question is just one SELECT. What happens if you execute the SELECT outside the procedure, do you also observe a slow down on the 2nd and further executions? If so, could you please run EXPLAIN on the first and the second execution and paste its result here?

If you don't observe the problem outside the procedure, can you modify the procedure so that it runs EXPLAIN SELECT before the SELECT, and, again, paste the result of the first and second EXPLAIN here?

If it so happens that the problem disappears after you add EXPLAIN, could you please give any idea on how big the tables are (hundreds, thousands or records) – in some cases I can make a reasonable guess based on the table name, but not always; also, approximately how many rows does the query from the procedure produce?

Thanks.

Shane created a good test case for MySQL, but it doesn't reproduce the bug on MariaDB 10.0.1 (at least not with default settings), so we still need to work on it.

I've created synthetic data for the reporter's schema which allows to reproduce the problem.
The difference in execution time is not as impressive as in the original description, but it's essential enough to be sure it's not a coincidence (3 sec vs 17 sec).
Reproducible on MariaDB 5.3-10.0 (and on MySQL 5.6). On MariaDB 5.2 the first query is equally slow.

I've also simplified the query a bit, and removed unnecessary structures. The procedure now looks like this:

CREATE PROCEDURE pr(in iRik year)
BEGIN
SELECT COUNT FROM t1
INNER JOIN t2 ON (t1.PredmetsID = t2.ID)
INNER JOIN t3 ON (t2.GroupID = t3.ID)
LEFT JOIN
(SELECT GROUP_CONCAT( t3.Name) AS PotokLec,t2.PotokID FROM t2
INNER JOIN t3 ON (t2.GroupID = t3.ID)
WHERE t2.PotokID IS NOT NULL
GROUP BY t2.PotokID
) AS a ON (t2.PotokID=a.potokid) AND (t1.Type=1)
LEFT JOIN
(SELECT GROUP_CONCAT( t3.Name) AS PotokPr,t2.PotokPrID FROM t2
INNER JOIN t3 ON (t2.GroupID = t3.ID)
WHERE t2.PotokPrID IS NOT NULL
GROUP BY t2.PotokPrID
) AS a1 ON (t2.PotokPrID=a1.potokPrid) AND (t1.Type=2)
LEFT JOIN
(SELECT GROUP_CONCAT( t3.Name) AS PotokLab,t2.PotokLabID FROM t2
INNER JOIN t3 ON (t2.GroupID = t3.ID)
WHERE t2.PotokLabID IS NOT NULL
GROUP BY t2.PotokLabID
) AS a2 ON (t2.PotokLabID=a2.potokLabid) AND (t1.Type=3)
;

To reproduce,

• start MariaDB server (all default settings will be enough);
• load the attached file (mysql -uroot test < mdev4171.sql);
• connect to the server;
• execute
  call pr(2012);
  call pr(2012);

Result:

MariaDB [test]> call pr(2012);
----------

COUNT

----------

----------
1 row in set (3.12 sec)

Query OK, 0 rows affected (3.12 sec)

MariaDB [test]> call pr(2012);
----------

COUNT

----------

----------
1 row in set (17.15 sec)

ANALYZE or FLUSH TABLES doesn't change anything.
For a new connection, again, the first execution is fast, and the next is slow.
If the same query is executed outside the procedure, there is no difference in execution time.
If I put EXPLAIN inside the procedure, it doesn't show any difference on the first and next executions. The shown plan is the same:

----------------------------------------------------------------------------------------------------------------------

----------------------------------------------------------------------------------------------------------------------

----------------------------------------------------------------------------------------------------------------------

Note

1003

select count(0) AS `COUNT` from `test`.`t1` join `test`.`t2` join `test`.`t3` left join (select group_concat(`test`.`t3`.`Name` separator ',') AS `PotokLec`,`test`.`t2`.`PotokID` AS `PotokID` from `test`.`t2` join `test`.`t3` where ((`test`.`t3`.`ID` = `test`.`t2`.`GroupID`) and (`test`.`t2`.`PotokID` is not null)) group by `test`.`t2`.`PotokID`) `a` on(((`a`.`PotokID` = `test`.`t2`.`PotokID`) and (`test`.`t1`.`Type` = 1) and (`test`.`t2`.`PotokID` is not null))) left join (select group_concat(`test`.`t3`.`Name` separator ',') AS `PotokPr`,`test`.`t2`.`PotokPrID` AS `PotokPrID` from `test`.`t2` join `test`.`t3` where ((`test`.`t3`.`ID` = `test`.`t2`.`GroupID`) and (`test`.`t2`.`PotokPrID` is not null)) group by `test`.`t2`.`PotokPrID`) `a1` on(((`a1`.`PotokPrID` = `test`.`t2`.`PotokPrID`) and (`test`.`t1`.`Type` = 2) and (`test`.`t2`.`PotokPrID` is not null))) left join (select group_concat(`test`.`t3`.`Name` separator ',') AS `PotokLab`,`test`.`t2`.`PotokLabID` AS `PotokLabID` from `test`.`t2` join `test`.`t3` where ((`test`.`t3`.`ID` = `test`.`t2`.`GroupID`) and (`test`.`t2`.`PotokLabID` is not null)) group by `test`.`t2`.`PotokLabID`) `a2` on(((`a2`.`PotokLabID` = `test`.`t2`.`PotokLabID`) and (`test`.`t1`.`Type` = 3) and (`test`.`t2`.`PotokLabID` is not null))) where ((`test`.`t2`.`ID` = `test`.`t1`.`PredmetsID`) and (`test`.`t3`.`ID` = `test`.`t2`.`GroupID`))

However, SHOW STATUS reveals a difference.
First execution of the procedure:
----------------------------------+

----------------------------------+

----------------------------------+

FLUSH STATUS, second execution of the procedure:
----------------------------------+

----------------------------------+

----------------------------------+

Sanja,

I switched priority to Minor for now, because there are still chances it's the upstream bug #68350, in which case it might make sense to wait for the fix to see if it's appropriate and applicable. However, I'm not sure it will be the case, since the test case from #68350 does not reproduce the issue on MariaDB. If you think it needs to be fixed independently in MariaDB, please feel free to change the priority to whatever you find suitable.

here is the difference in explainn of 2 executions:
diff log1 log2
5c5
< 1 PRIMARY t3 eq_ref PRIMARY PRIMARY 4 test.t2.GroupID 1 100.00 Using index
—
> 1 PRIMARY t3 eq_ref PRIMARY PRIMARY 4 test.t2.GroupID 1 100.00

the full explain for both calls is here:
call pr(2012);
id select_type table type possible_keys key key_len ref rows filtered Extra
1 PRIMARY t1 ALL NULL NULL NULL NULL 86365 100.00 Using where
1 PRIMARY t2 eq_ref PRIMARY PRIMARY 4 test.t1.PredmetsID 1 100.00 Using where
1 PRIMARY t3 eq_ref PRIMARY PRIMARY 4 test.t2.GroupID 1 100.00 Using index
1 PRIMARY <derived2> ref key0 key0 5 test.t2.PotokID 10 100.00 Using where
1 PRIMARY <derived3> ref key0 key0 5 test.t2.PotokPrID 10 100.00 Using where
1 PRIMARY <derived4> ref key0 key0 5 test.t2.PotokLabID 10 100.00 Using where
4 DERIVED t2 ALL NULL NULL NULL NULL 32139 100.00 Using where; Using filesort
4 DERIVED t3 eq_ref PRIMARY PRIMARY 4 test.t2.GroupID 1 100.00
3 DERIVED t2 ALL NULL NULL NULL NULL 32139 100.00 Using where; Using filesort
3 DERIVED t3 eq_ref PRIMARY PRIMARY 4 test.t2.GroupID 1 100.00
2 DERIVED t2 ALL NULL NULL NULL NULL 32139 100.00 Using where; Using filesort
2 DERIVED t3 eq_ref PRIMARY PRIMARY 4 test.t2.GroupID 1 100.00
Warnings:
Note 1003 select count(0) AS `COUNT` from `test`.`t1` join `test`.`t2` join `test`.`t3` left join (select group_concat(`test`.`t3`.`Name` separator ',') AS `PotokLec`,`test`.`t2`.`PotokID` AS `PotokID` from `test`.`t2` join `test`.`t3` where ((`test`.`t3`.`ID` = `test`.`t2`.`GroupID`) and (`test`.`t2`.`PotokID` is not null)) group by `test`.`t2`.`PotokID`) `a` on(((`a`.`PotokID` = `test`.`t2`.`PotokID`) and (`test`.`t1`.`Type` = 1) and (`test`.`t2`.`PotokID` is not null))) left join (select group_concat(`test`.`t3`.`Name` separator ',') AS `PotokPr`,`test`.`t2`.`PotokPrID` AS `PotokPrID` from `test`.`t2` join `test`.`t3` where ((`test`.`t3`.`ID` = `test`.`t2`.`GroupID`) and (`test`.`t2`.`PotokPrID` is not null)) group by `test`.`t2`.`PotokPrID`) `a1` on(((`a1`.`PotokPrID` = `test`.`t2`.`PotokPrID`) and (`test`.`t1`.`Type` = 2) and (`test`.`t2`.`PotokPrID` is not null))) left join (select group_concat(`test`.`t3`.`Name` separator ',') AS `PotokLab`,`test`.`t2`.`PotokLabID` AS `PotokLabID` from `test`.`t2` join `test`.`t3` where ((`test`.`t3`.`ID` = `test`.`t2`.`GroupID`) and (`test`.`t2`.`PotokLabID` is not null)) group by `test`.`t2`.`PotokLabID`) `a2` on(((`a2`.`PotokLabID` = `test`.`t2`.`PotokLabID`) and (`test`.`t1`.`Type` = 3) and (`test`.`t2`.`PotokLabID` is not null))) where ((`test`.`t3`.`ID` = `test`.`t2`.`GroupID`) and (`test`.`t2`.`ID` = `test`.`t1`.`PredmetsID`))
call pr(2012);
id select_type table type possible_keys key key_len ref rows filtered Extra
1 PRIMARY t1 ALL NULL NULL NULL NULL 86365 100.00 Using where
1 PRIMARY t2 eq_ref PRIMARY PRIMARY 4 test.t1.PredmetsID 1 100.00 Using where
1 PRIMARY t3 eq_ref PRIMARY PRIMARY 4 test.t2.GroupID 1 100.00
1 PRIMARY <derived2> ref key0 key0 5 test.t2.PotokID 10 100.00 Using where
1 PRIMARY <derived3> ref key0 key0 5 test.t2.PotokPrID 10 100.00 Using where
1 PRIMARY <derived4> ref key0 key0 5 test.t2.PotokLabID 10 100.00 Using where
4 DERIVED t2 ALL NULL NULL NULL NULL 32139 100.00 Using where; Using filesort
4 DERIVED t3 eq_ref PRIMARY PRIMARY 4 test.t2.GroupID 1 100.00
3 DERIVED t2 ALL NULL NULL NULL NULL 32139 100.00 Using where; Using filesort
3 DERIVED t3 eq_ref PRIMARY PRIMARY 4 test.t2.GroupID 1 100.00
2 DERIVED t2 ALL NULL NULL NULL NULL 32139 100.00 Using where; Using filesort
2 DERIVED t3 eq_ref PRIMARY PRIMARY 4 test.t2.GroupID 1 100.00
Warnings:
Note 1003 select count(0) AS `COUNT` from `test`.`t1` join `test`.`t2` join `test`.`t3` left join (select group_concat(`test`.`t3`.`Name` separator ',') AS `PotokLec`,`test`.`t2`.`PotokID` AS `PotokID` from `test`.`t2` join `test`.`t3` where ((`test`.`t3`.`ID` = `test`.`t2`.`GroupID`) and (`test`.`t2`.`PotokID` is not null)) group by `test`.`t2`.`PotokID`) `a` on(((`a`.`PotokID` = `test`.`t2`.`PotokID`) and (`test`.`t1`.`Type` = 1) and (`test`.`t2`.`PotokID` is not null))) left join (select group_concat(`test`.`t3`.`Name` separator ',') AS `PotokPr`,`test`.`t2`.`PotokPrID` AS `PotokPrID` from `test`.`t2` join `test`.`t3` where ((`test`.`t3`.`ID` = `test`.`t2`.`GroupID`) and (`test`.`t2`.`PotokPrID` is not null)) group by `test`.`t2`.`PotokPrID`) `a1` on(((`a1`.`PotokPrID` = `test`.`t2`.`PotokPrID`) and (`test`.`t1`.`Type` = 2) and (`test`.`t2`.`PotokPrID` is not null))) left join (select group_concat(`test`.`t3`.`Name` separator ',') AS `PotokLab`,`test`.`t2`.`PotokLabID` AS `PotokLabID` from `test`.`t2` join `test`.`t3` where ((`test`.`t3`.`ID` = `test`.`t2`.`GroupID`) and (`test`.`t2`.`PotokLabID` is not null)) group by `test`.`t2`.`PotokLabID`) `a2` on(((`a2`.`PotokLabID` = `test`.`t2`.`PotokLabID`) and (`test`.`t1`.`Type` = 3) and (`test`.`t2`.`PotokLabID` is not null))) where ((`test`.`t3`.`ID` = `test`.`t2`.`GroupID`) and (`test`.`t2`.`ID` = `test`.`t1`.`PredmetsID`))

The test suite to see explain difference (needs mysqltest recompile)

To the t3 which loose "Using index" added alias (t33) to catch it in setup_table_map(), then set watchpoint on its covering_keys->map, then on the second execution appaared that this table has alias just t3 and so GROUP_CONCAT fix_fields drop covering_keys->map (i.e. table was used in the derived table). I can't explain (yet) how it happened)

covering_keys is part of TABLE so it is no surprize that it does not stay after reopen.

I couldn't reproduce it on latest 5.5 and 10.0-base.

Still reproducible on the current 5.5 and 10.0 (revno 4471).

The upstream bug was fixed in 5.6.12, so there is no point waiting any longer:

revno: 5057

revision-id: neeraj.x.bisht@oracle.com-20130430092409-20y1i3lrtlx1izmn

parent: luis.soares@oracle.com-20130429215526-ry0xgj1pvkaj0dxf

committer: Neeraj Bisht <neeraj.x.bisht@oracle.com>

branch nick: 5.6

timestamp: Tue 2013-04-30 14:54:09 +0530

message:

  Bug#16346367 : QUERY PROC RE-EXECUTE OF STORED ROUTINE, INEFFICIENT QUERY PLAN

  Problem:-

  In derived tables implementation, We only get to use indexes on derived tables 

  on the first execution of a procedure and  in later execution we are not able 

  to use indexes.

  Analysis:-

  In case of derived tables, we call add_key_field() to add new fake keys for 

  range optimizer. To choose the best key to read data. After creating the actual 

  keys from this fake keys. 

  We set the variable in TABLE_LIST::derived_keys_ready, to show that actual 

  keys are created.

  This table_list is maintained in the memory after our exection is completed.                       

  So when we call our procedure second time, this TABLE_LIST::derived_keys_ready 

  is already set and we assume that actual keys are already being created, but we 

  will not find any key, which cause change in query execution plan.

  Solution:-

  Reset the TABLE_LIST::derived_keys_ready at the time JOIN_TAB::cleanup.

Please consider either merging the fix if applicable or fixing it independently.

Yes. It looks like a fixed. But inability to make tests automatically prevent me to find what commit did it.