MySQL Bugs: #59926: Query With Stored Function Call Takes Longer With Each Run

Bug #59926	Query With Stored Function Call Takes Longer With Each Run
Submitted:	3 Feb 2011 20:01	Modified:	21 Jul 2011 11:27
Reporter:	Anthony Galano	Email Updates:
Status:	Duplicate	Impact on me:	None
Category:	MySQL Server: Command-line Clients	Severity:	S2 (Serious)
Version:	5.5.8, 5.6.2	OS:	Any
Assigned to:		CPU Architecture:	Any
Tags:	performance, query

Description:
When I run a query with a stored function the query run gets consistently longer each time. The time added to the query is consistent for each run and is dependent on the number of rows in the query.

For example with the test database I've included with 626 rows, the query runs the first time in .4ms, the next run is .9ms, the next run is 1.85s, and so forth. In our production environment where this query is run on ~15k rows, the time increases by a consistent 5 seconds per run. 

Aside from the consistently increasing query times, initial performance is worse than previous MySQL version 5.1.34 which we are currently running in production. 

Both machines are running CentOS 5.5 with Xenon Processors. The current 5.1.34 machine has 8GB of RAM, the 5.5.8 machine has 16GB of ram. 

A full thread of this issues in the forums can be found here:

http://forums.mysql.com/read.php?24,404798,404798#msg-404798

Which contains the my.cnf, a complete description of the problem, server variables, a test dump of the database and sample cases. It was verified by other forum members.

How to repeat:
Load the sample database posted in the the support forum thread:

http://forums.mysql.com/read.php?24,404798,405541#msg-405541

Run the following query:

[code]
mysql> show variables like 'version';
+---------------+-----------+
| Variable_name | Value |
+---------------+-----------+
| version | 5.5.8-log |
+---------------+-----------+
1 row in set (0.00 sec)

mysql> SELECT SQL_NO_CACHE count(*) FROM records WHERE ConvertGMTDateToLocalDate(ClockIn,-8,1,-7) BETWEEN '2011-01-01 00:00:00' AND '2011-01-25 23:59:59';
+----------+
| count(*) |
+----------+
| 22 |
+----------+
1 row in set (.40 sec)

mysql> SELECT SQL_NO_CACHE count(*) FROM records WHERE ConvertGMTDateToLocalDate(ClockIn,-8,1,-7) BETWEEN '2011-01-01 00:00:00' AND '2011-01-25 23:59:59';
+----------+
| count(*) |
+----------+
| 22 |
+----------+
1 row in set (.90 sec)

mysql> SELECT SQL_NO_CACHE count(*) FROM records WHERE ConvertGMTDateToLocalDate(ClockIn,-8,1,-7) BETWEEN '2011-01-01 00:00:00' AND '2011-01-25 23:59:59';
+----------+
| count(*) |
+----------+
| 22 |
+----------+
1 row in set (1.85 sec)
[/code]

Other than the increasing query times, I would expect initial performance to at least match our current 5.1.34 production database benchmarks:

mysql> show variables like 'version';
+---------------+----------------------+
| Variable_name | Value |
+---------------+----------------------+
| version | 5.1.34-community-log |
+---------------+----------------------+
1 row in set (0.02 sec)

mysql> SELECT SQL_NO_CACHE count(*) FROM records WHERE ConvertGMTDateToLocalDate(ClockIn,-8,1,-7) BETWEEN '2011-01-01 00:00:00' AND '2011-01-25 23:59:59';
+----------+
| count(*) |
+----------+
| 22 |
+----------+
1 row in set (0.16 sec)

mysql> SELECT SQL_NO_CACHE count(*) FROM records WHERE ConvertGMTDateToLocalDate(ClockIn,-8,1,-7) BETWEEN '2011-01-01 00:00:00' AND '2011-01-25 23:59:59';
+----------+
| count(*) |
+----------+
| 22 |
+----------+
1 row in set (0.17 sec)

mysql> SELECT SQL_NO_CACHE count(*) FROM records WHERE ConvertGMTDateToLocalDate(ClockIn,-8,1,-7) BETWEEN '2011-01-01 00:00:00' AND '2011-01-25 23:59:59';
+----------+
| count(*) |
+----------+
| 22 |
+----------+
1 row in set (0.16 sec) 

Suggested fix:
Unknown.

Changed title.

Thank you for the report.

Please provide definition of ConvertGMTDateToLocalDate.

Here it is below. You can get the full database with sample data table at this post: http://forums.mysql.com/read.php?24,404798,405541#msg-405541

-- 
-- Dumping routines for database 'test'
-- 
/*!50003 DROP FUNCTION IF EXISTS `ConvertGMTDateToLocalDate` */;
/*!50003 SET @saved_cs_client = @@character_set_client */ ;
/*!50003 SET @saved_cs_results = @@character_set_results */ ;
/*!50003 SET @saved_col_connection = @@collation_connection */ ;
/*!50003 SET character_set_client = latin1 */ ;
/*!50003 SET character_set_results = latin1 */ ;
/*!50003 SET collation_connection = latin1_swedish_ci */ ;
/*!50003 SET @saved_sql_mode = @@sql_mode */ ;
/*!50003 SET sql_mode = '' */ ;
DELIMITER ;;
/*!50003 CREATE*/ /*!50020 DEFINER=`root`@`%`*/ /*!50003 FUNCTION `ConvertGMTDateToLocalDate`(
WorkDate datetime,
TimezoneOffset decimal(3,1),
DSTEnabled tinyint(3) unsigned,
TimezoneDSTOffset decimal(3,1)
) RETURNS datetime
DETERMINISTIC
BEGIN

DECLARE LocalDateTime datetime;
DECLARE DSTStart datetime;
DECLARE DSTEnd datetime;
DECLARE TimezoneOffsetHour int;
DECLARE TimezoneOffsetMinute int;
DECLARE TimezoneDSTOffsetHour int;
DECLARE TimezoneDSTOffsetMinute int;

IF ( TimezoneOffset < 0 )
THEN
SET TimezoneOffsetHour = CEILING(TimezoneOffset);
SET TimezoneOffsetMinute = ABS(60 * (TimezoneOffset - CEILING(TimezoneOffset)));
ELSE
SET TimezoneOffsetHour = FLOOR(TimezoneOffset);
SET TimezoneOffsetMinute = ABS(60 * (TimezoneOffset - FLOOR(TimezoneOffset)));
END IF;

IF ( TimezoneDSTOffset < 0 )
THEN
SET TimezoneDSTOffsetHour = CEILING(TimezoneDSTOffset);
SET TimezoneDSTOffsetMinute = ABS(60 * (TimezoneDSTOffset - CEILING(TimezoneDSTOffset)));
ELSE
SET TimezoneDSTOffsetHour = FLOOR(TimezoneDSTOffset);
SET TimezoneDSTOffsetMinute = ABS(60 * (TimezoneDSTOffset - FLOOR(TimezoneDSTOffset)));
END IF;

IF ( DSTEnabled = 1 )
THEN
SET DSTStart = GetDaylightSavingTimeStart(YEAR(WorkDate));
SET DSTEnd = GetDaylightSavingTimeEnd(YEAR(WorkDate));

SET DSTStart = STR_TO_DATE(CONCAT(YEAR(DSTStart),'-',MONTH(DSTStart),'-',DAY(DSTStart),'-',ABS(TimezoneOffsetHour)+2,'-',TimezoneOffsetMinute,'-0'),'%Y-%m-%d-%H-%i-%s');
SET DSTEnd = STR_TO_DATE(CONCAT(YEAR(DSTEnd),'-',MONTH(DSTEnd),'-',DAY(DSTEnd),'-',ABS(TimezoneDSTOffsetHour)+2,'-',TimezoneDSTOffsetMinute,'-0'),'%Y-%m-%d-%H-%i-%s');

IF ( WorkDate >= DSTStart AND WorkDate < DSTEnd )
THEN
SET LocalDateTime = DATE_ADD(WorkDate,INTERVAL CONCAT(TimezoneDSTOffsetHour,':',TimezoneDSTOffsetMinute) HOUR_MINUTE);
ELSE
SET LocalDateTime = DATE_ADD(WorkDate,INTERVAL CONCAT(TimezoneOffsetHour,':',TimezoneOffsetMinute) HOUR_MINUTE);
END IF;
ELSE
SET LocalDateTime = DATE_ADD(WorkDate,INTERVAL CONCAT(TimezoneOffsetHour,':',TimezoneOffsetMinute) HOUR_MINUTE);
END IF;

RETURN LocalDateTime;

END */;;
DELIMITER ;
/*!50003 SET sql_mode = @saved_sql_mode */ ;
/*!50003 SET character_set_client = @saved_cs_client */ ;
/*!50003 SET character_set_results = @saved_cs_results */ ;
/*!50003 SET collation_connection = @saved_col_connection */ ;
/*!50003 DROP FUNCTION IF EXISTS `GetDaylightSavingTimeEnd` */;
/*!50003 SET @saved_cs_client = @@character_set_client */ ;
/*!50003 SET @saved_cs_results = @@character_set_results */ ;
/*!50003 SET @saved_col_connection = @@collation_connection */ ;
/*!50003 SET character_set_client = utf8 */ ;
/*!50003 SET character_set_results = utf8 */ ;
/*!50003 SET collation_connection = utf8_general_ci */ ;
/*!50003 SET @saved_sql_mode = @@sql_mode */ ;
/*!50003 SET sql_mode = '' */ ;
DELIMITER ;;
/*!50003 CREATE*/ /*!50020 DEFINER=`root`@`%`*/ /*!50003 FUNCTION `GetDaylightSavingTimeEnd`(
TheYear int
) RETURNS date
DETERMINISTIC
BEGIN

DECLARE TheEndDate date;
DECLARE LastSunday int;

IF ( TheYear < 2007 )
THEN
SET LastSunday = GetNthOccOfDayInMonth(5,1,10,TheYear);
IF ( LastSunday <= -1 )
THEN
SET TheEndDate = STR_TO_DATE(CONCAT(TheYear,'-10-',GetNthOccOfDayInMonth(4,1,10,TheYear)),'%Y-%m-%d');
ELSE
SET TheEndDate = STR_TO_DATE(CONCAT(TheYear,'-10-',LastSunday),'%Y-%m-%d');
END IF;
ELSE
SET TheEndDate = STR_TO_DATE(CONCAT(TheYear,'-11-',GetNthOccOfDayInMonth(1,1,11,TheYear)),'%Y-%m-%d');
END IF;

RETURN TheEndDate;

END */;;
DELIMITER ;
/*!50003 SET sql_mode = @saved_sql_mode */ ;
/*!50003 SET character_set_client = @saved_cs_client */ ;
/*!50003 SET character_set_results = @saved_cs_results */ ;
/*!50003 SET collation_connection = @saved_col_connection */ ;
/*!50003 DROP FUNCTION IF EXISTS `GetDaylightSavingTimeStart` */;
/*!50003 SET @saved_cs_client = @@character_set_client */ ;
/*!50003 SET @saved_cs_results = @@character_set_results */ ;
/*!50003 SET @saved_col_connection = @@collation_connection */ ;
/*!50003 SET character_set_client = utf8 */ ;
/*!50003 SET character_set_results = utf8 */ ;
/*!50003 SET collation_connection = utf8_general_ci */ ;
/*!50003 SET @saved_sql_mode = @@sql_mode */ ;
/*!50003 SET sql_mode = '' */ ;
DELIMITER ;;
/*!50003 CREATE*/ /*!50020 DEFINER=`root`@`%`*/ /*!50003 FUNCTION `GetDaylightSavingTimeStart`(
TheYear int
) RETURNS date
DETERMINISTIC
BEGIN

DECLARE TheStartDate date;

IF ( TheYear < 2007 )
THEN
SET TheStartDate = STR_TO_DATE(CONCAT(TheYear,'-4-',GetNthOccOfDayInMonth(1,1,4,TheYear)),'%Y-%m-%d');
ELSE
SET TheStartDate = STR_TO_DATE(CONCAT(TheYear,'-3-',GetNthOccOfDayInMonth(2,1,3,TheYear)),'%Y-%m-%d');
END IF;

RETURN TheStartDate;

END */;;
DELIMITER ;
/*!50003 SET sql_mode = @saved_sql_mode */ ;
/*!50003 SET character_set_client = @saved_cs_client */ ;
/*!50003 SET character_set_results = @saved_cs_results */ ;
/*!50003 SET collation_connection = @saved_col_connection */ ;
/*!50003 DROP FUNCTION IF EXISTS `GetNthOccOfDayInMonth` */;
/*!50003 SET @saved_cs_client = @@character_set_client */ ;
/*!50003 SET @saved_cs_results = @@character_set_results */ ;
/*!50003 SET @saved_col_connection = @@collation_connection */ ;
/*!50003 SET character_set_client = utf8 */ ;
/*!50003 SET character_set_results = utf8 */ ;
/*!50003 SET collation_connection = utf8_general_ci */ ;
/*!50003 SET @saved_sql_mode = @@sql_mode */ ;
/*!50003 SET sql_mode = '' */ ;
DELIMITER ;;
/*!50003 CREATE*/ /*!50020 DEFINER=`root`@`%`*/ /*!50003 FUNCTION `GetNthOccOfDayInMonth`(
NthOccurrence int,
TheDayOfWeek int,
TheMonth tinyint,
TheYear int
) RETURNS int(11)
DETERMINISTIC
BEGIN
DECLARE TheDayInMonth int(11);
DECLARE DateToTest date;
DECLARE DayOfWeekToTest int(11);

SET TheDayInMonth = 0;
SET DateToTest = STR_TO_DATE(CONCAT(TheYear,'-',TheMonth,'-',1),'%Y-%m-%d');
SET DayOfWeekToTest = DAYOFWEEK(DateToTest);

IF ( TheDayOfWeek < DayOfWeekToTest )
THEN
SET TheDayInMonth = (1 + (NthOccurrence*7) + ((TheDayOfWeek-DayOfWeekToTest) % 7));
ELSE
SET TheDayInMonth = (1 + ((NthOccurrence-1)*7) + ((TheDayOfWeek-DayOfWeekToTest) % 7));
END IF;

IF ( TheDayInMonth > DAY(LAST_DAY(DateToTest)) OR TheDayInMonth < 1 )
THEN
RETURN -1;
ELSE
RETURN TheDayInMonth;
END IF;

END */;;
DELIMITER ;

Thank you for the feedback.

Verified as described using function definitions and table data from forum post provided.

This is client issue. Workaround: use client from 5.1 distribution.

triage: Not clear how it was concluded this is a client issue setting to MRU as issue needs to be understood.

> This is client issue. Workaround: use client from 5.1 distribution.

WRONG. The same behaviour occurs with the 5.1 client.

Having a similar problem.  A query containing a user defined function runs longer and longer with each successive execution.  The server upgraded is a slave and it’s causing replication to fall further and further behind.  Eventually, Mysql needs to be restarted for replication to catch up.

A simpler test case:

I originally tried a function that only did "return a" but that didn't seem to trigger the problem.  Adding an IF was enough to get the time growth.

After performing this test I created an identical "test_userfunc3" function without "DETERMINISTIC"  and got a very similar growth chart - starting at .13s and exceeding 5 seconds by the 8th successive benchmark (of 5000 execution).

FUNCTION `test_userfunc2`(a text) RETURNS text CHARSET utf8
    DETERMINISTIC
BEGIN
  IF a = 'test' THEN
    RETURN a;
  END IF;
END

mysql> select benchmark(5000, test_userfunc2('test')) \G
*************************** 1. row ***************************
benchmark(5000, test_userfunc2('test')): 0
1 row in set (0.13 sec)

mysql> select benchmark(5000, test_userfunc2('test')) \G
*************************** 1. row ***************************
benchmark(5000, test_userfunc2('test')): 0
1 row in set (0.29 sec)

mysql> select benchmark(5000, test_userfunc2('test')) \G
*************************** 1. row ***************************
benchmark(5000, test_userfunc2('test')): 0
1 row in set (0.44 sec)

mysql> select benchmark(5000, test_userfunc2('test')) \G
*************************** 1. row ***************************
benchmark(5000, test_userfunc2('test')): 0
1 row in set (0.61 sec)

mysql> select benchmark(5000, test_userfunc2('test')) \G
*************************** 1. row ***************************
benchmark(5000, test_userfunc2('test')): 0
1 row in set (0.77 sec)

mysql> select benchmark(5000, test_userfunc2('test')) \G
*************************** 1. row ***************************
benchmark(5000, test_userfunc2('test')): 0
1 row in set (0.96 sec)

mysql> select benchmark(5000, test_userfunc2('test')) \G
*************************** 1. row ***************************
benchmark(5000, test_userfunc2('test')): 0
1 row in set (1.92 sec)

I have the same problem with a stored procedure that is DETERMINISTIC and NO SQL.  It is in the WHERE clause of a complex query so the function is executed on each row of a table.  

Initially the query runs in under 1 second, but then it runs about 2 seconds longer each time it is run again. 

I can reset it back to its shortest time by restarting MySql -- or -- by recreating the function (i.e. DROP FUNCTION ...  CREATE FUNCTION ... )

I am running version 5.5.10 Community x86 Win32 on Windows-XP.

WORKAROUND FOUND! 

If the information_schema ROUTINES LAST_ALTERED is changed for the stored function prior to the execution of the query, the performance does not degrade. 

Therefore, prior to each execution of the query, perform an executeUpdate with 
"ALTER FUNCTION yourfunctioname COMMENT "Altered comment" .

Closed as a duplicate of Bug#60025.