Bug #107327 High Memory Usage When Running Stored Procedure

Submitted: 18 May 2022 11:51 Modified: 5 Oct 2022 17:41
Reporter: Steven Azzopardi Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Stored Routines Severity:S2 (Serious)
Version:8.0.27, 8.0.28, 8.0.29 OS:Linux
Assigned to: CPU Architecture:Any
Tags: regression

[18 May 2022 11:51] Steven Azzopardi
Description:
Following a recent upgrade to MySQL 8.0.27 it was noticed that a particular query in our platform started consuming high amounts of memory compared to a previous version. The query in question is problematic when it is run within a stored procedure, when running it as a native query the issue does not occur. After enabling performance_schema it seems that the following is the culprit that consumes the most memory 

memory/sql/sp_head::execute_mem_root

When trying the same procedure in MySQL 8.0.26 the memory issue does not occur when running through a stored procedure.

How to repeat:
Below test case:

1) CREATE DATABASE temp_tables
2) Import Data from processor_sample.sql
3) Create procedure from processor_pending_SP.sql
4) Run native query from processor_pending_query.sql, memory should not spike excessively in performance_schema.`memory_summary_by_thread_by_event_name`
5) Run call processorPending(); , memory will spike excessively in performance_schema.`memory_summary_by_thread_by_event_name` for EVENT_NAME "memory/sql/sp_head::execute_mem_root"

In MySQL 8.0.26 EVENT_NAME "memory/sql/sp_head::execute_mem_root" does not spike
[18 May 2022 11:52] Steven Azzopardi
Native Query

Attachment: processor_pending_query.sql (application/octet-stream, text), 492 bytes.

[18 May 2022 11:52] Steven Azzopardi
Stored Procedure

Attachment: processor_pending_SP.sql (application/octet-stream, text), 609 bytes.

[18 May 2022 12:33] Steven Azzopardi
Uploaded mysql-bug-data-107327.zip to SFTP , it contains sample data file processor_sample.sql referred to in test case.
[19 May 2022 12:21] MySQL Verification Team
Hello Steven Azzopardi,

Thank you for the report.
Verified as described.

==
8.0.29 - call to sp trigger spike in memory usage(temporarily, decreases after call to the sp finishes)
8.0.26 - call to sp don't trigger spike in memory

regards,
Umesh
[20 May 2022 12:27] Shane Bester
8.0.29 memory heap profile

Attachment: mybin.hprof.0238.heap.pdf (application/pdf, text), 23.33 KiB.

[20 May 2022 12:29] Shane Bester
Will upload the 8.0.29 heap profile in .txt format soon.
We can see the major allocations:

Leak of 250393696 bytes in 4 objects allocated from:
	@ 01f7c298 unknown
	@ 0000000001f7809a MEM_ROOT::AllocBlock ./obj/mysys/../../mysqlcom-8.0.29/mysys/my_alloc.cc:88
	@ 0000000001f7813f MEM_ROOT::ForceNewBlock ./obj/mysys/../../mysqlcom-8.0.29/mysys/my_alloc.cc:149
	@ 0000000001f781c4 MEM_ROOT::AllocSlow ./obj/mysys/../../mysqlcom-8.0.29/mysys/my_alloc.cc:139
	@ 0000000000e64929 THD::nocheck_register_item_tree_change ./obj/sql/../../mysqlcom-8.0.29/sql/sql_class.cc:1942
	@ 000000000115f530 Item_cache::store ./obj/sql/../../mysqlcom-8.0.29/sql/item.cc:9390
	@ 0000000001244005 Item_sum_hybrid::clear ./obj/sql/../../mysqlcom-8.0.29/sql/item_sum.cc:2729
	@ 00000000013dbbf8 AggregateIterator::Read ./obj/sql/../../mysqlcom-8.0.29/sql/iterators/composite_iterators.cc:300
	@ 00000000013d9e63 FilterIterator::Read ./obj/sql/../../mysqlcom-8.0.29/sql/iterators/composite_iterators.cc:71
	@ 0000000000fb81f2 Query_expression::ExecuteIteratorQuery ./obj/sql/../../mysqlcom-8.0.29/sql/sql_union.cc:1302
	@ 0000000000fb83db Query_expression::execute ./obj/sql/../../mysqlcom-8.0.29/sql/sql_union.cc:1355
	@ 0000000000f46e54 Sql_cmd_dml::execute ./obj/sql/../../mysqlcom-8.0.29/sql/sql_select.cc:584
	@ 0000000000ee5c17 mysql_execute_command ./obj/sql/../../mysqlcom-8.0.29/sql/sql_parse.cc:4576
	@ 0000000000e3f8c0 sp_instr_stmt::exec_core ./obj/sql/../../mysqlcom-8.0.29/sql/sp_instr.cc:964
	@ 0000000000e417a8 sp_lex_instr::reset_lex_and_exec_core ./obj/sql/../../mysqlcom-8.0.29/sql/sp_instr.cc:441
	@ 0000000000e4288b sp_lex_instr::validate_lex_and_execute_core ./obj/sql/../../mysqlcom-8.0.29/sql/sp_instr.cc:725
	@ 0000000000e4422b sp_instr_stmt::execute ./obj/sql/../../mysqlcom-8.0.29/sql/sp_instr.cc:890
	@ 0000000000e37851 sp_head::execute ./obj/sql/../../mysqlcom-8.0.29/sql/sp_head.cc:2221
	@ 0000000000e3aa9c sp_head::execute_procedure ./obj/sql/../../mysqlcom-8.0.29/sql/sp_head.cc:2866
	@ 0000000001382f37 Sql_cmd_call::execute_inner ./obj/sql/../../mysqlcom-8.0.29/sql/sql_call.cc:235
	@ 0000000000f46e54 Sql_cmd_dml::execute ./obj/sql/../../mysqlcom-8.0.29/sql/sql_select.cc:584
[20 May 2022 12:30] Shane Bester
.txt heap profile of 8.0.29

Attachment: mybin.hprof.0238.heap.zip (application/zip, text), 1.10 MiB.

[5 Oct 2022 17:41] Jon Stephens
Documented fix as follows in the MySQL 8.0.32 changelog:

    Following an upgrade to MySQL 8.0.27 a specific query started
    consuming comparatively high amounts of memory whenever it was
    run within a stored procedure.

Closed.
[31 Mar 2024 4:15] Gabriele Mittani
While stored procedures appear slower and consume more energy in version 8.0.27, 8.0.28, 8.0.29, I've noticed improvement starting with release 8.0.31. If it's not done already, I suggest an upgrade to mitigate this problem.

Kind regards,
Gabriele MITTANI
https://flowerdeliveryitaly.it/

Portions of this website are copyright © 2001, 2002 The PHP Group

Page generated in 0.069 sec. using MySQL 8.4.7-u6-cloud

Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the respective copyright holders.
It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.