[MDEV-31742] incorrect examined rows in case of stored function usage Created: 2023-07-19  Updated: 2023-09-27  Resolved: 2023-09-27

Status: Closed
Project: MariaDB Server
Component/s: OTHER
Affects Version/s: 10.4, 10.5, 10.6, 10.9, 10.10, 10.11
Fix Version/s: 10.4.32, 10.5.23, 10.6.16, 10.10.7, 10.11.6, 11.0.4, 11.1.3

Type: Bug Priority: Major
Reporter: Oleksandr Byelkin Assignee: Oleksandr Byelkin
Resolution: Fixed Votes: 0
Labels: None

Issue Links:
Relates
relates to MDEV-30820 slow log Rows_examined out of range Closed

 Description   

Both SSELECTs should produce the same (or similar) examined rows numer but it is 95179 vs 17716591112119384090

CREATE TABLE `tab_MDEV_30820` (
`ID` int(11) NOT NULL AUTO_INCREMENT,
`NAME_F` varchar(50) DEFAULT NULL,
  PRIMARY KEY (`ID`)
);
 
 CREATE TABLE `tab2` (
  `ID` int(11) NOT NULL AUTO_INCREMENT,
  `TAB1_ID` int(11) DEFAULT NULL,
  PRIMARY KEY (`id`)
);
 
--delimiter //
CREATE FUNCTION `get_zero`() RETURNS int(11)
BEGIN
    RETURN(0) ;
END
//
 
for i in 1..100 do insert into tab_MDEV_30820 values (null,'qwerty'); end for ; //
for i in 1..1000 do insert into tab2 values (null,round(rand()*10000)); end for ; //
 
--delimiter ;
 
SET @old_slow_query_log= @@global.slow_query_log;
SET @old_log_output= @@global.log_output;
SET @old_long_query_time= @@long_query_time;
SET GLOBAL log_output= "TABLE";
SET GLOBAL slow_query_log= ON;
SET SESSION long_query_time= 0;
 
SELECT 0 as zero, (SELECT ID FROM tab2 where tab2.TAB1_ID = tab_MDEV_30820.ID LIMIT 1) AS F1 FROM tab_MDEV_30820 ORDER BY 2 DESC LIMIT 2;
 
SELECT get_zero() as zero, (SELECT ID FROM tab2 where tab2.TAB1_ID = tab_MDEV_30820.ID LIMIT 1) AS F1 FROM tab_MDEV_30820 ORDER BY 2 DESC LIMIT 2;
 
SELECT rows_examined FROM mysql.slow_log WHERE sql_text LIKE '%SELECT%tab_MDEV_30820%';
 
## Reset to initial values
SET @@long_query_time= @old_long_query_time;
SET @@global.log_output= @old_log_output;
SET @@global.slow_query_log= @old_slow_query_log;
 
drop table tab_MDEV_30820, tab2;
drop function get_zero;



 Comments   
Comment by Oleksandr Byelkin [ 2023-07-19 ]

commit 64ac6ed3e357af743c70ea1d6ddf8fb699d51589 (HEAD -> bb-10.4-MDEV-30820, origin/bb-10.4-MDEV-30820)
Author: Oleksandr Byelkin <sanja@mariadb.com>
Date:   Wed Jul 19 16:14:39 2023 +0200
 
    MDEV-31742 incorrect examined rows in case of stored function usage
    
    The counter is global so we do not need add backup to it
    if we do not zero it after taking the backup.

Comment by Lena Startseva [ 2023-09-27 ]

sanja, plz, fix test main.log_slow, it fails with view-protocol:

main.log_slow                            w4 [ fail ]
        Test ended at 2023-09-27 04:39:30
CURRENT_TEST: main.log_slow
--- /home/buildbot/amd64-ubuntu-2004-fulltest/build/mysql-test/main/log_slow.result	2023-09-27 03:32:01.000000000 +0000
+++ /home/buildbot/amd64-ubuntu-2004-fulltest/build/mysql-test/main/log_slow.reject	2023-09-27 04:39:30.112633891 +0000
@@ -173,8 +173,6 @@
 # should be the same rows_examined
 SELECT rows_examined FROM mysql.slow_log WHERE sql_text LIKE '%SELECT%tab_MDEV_30820%';
 rows_examined
-100202
-100202
 SET @@long_query_time= @old_long_query_time;
 SET @@global.log_output= @old_log_output;
 SET @@global.slow_query_log= @old_slow_query_log;
mysqltest: Result length mismatch

Comment by Oleksandr Byelkin [ 2023-09-27 ]

fixed

Generated at Thu Feb 08 10:26:08 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.