[MDEV-29404] Warning: Memory not freed: 80/104/16400/16320/16424 on PREPARE Created: 2022-08-29  Updated: 2023-11-28

Status: Confirmed
Project: MariaDB Server
Component/s: Optimizer, Prepared Statements
Affects Version/s: 10.3, 10.4, 10.5, 10.6, 10.7, 10.8, 10.9, 10.10, 10.11
Fix Version/s: 10.4, 10.5, 10.6, 10.11, 11.0

Type: Bug Priority: Major
Reporter: Roel Van de Paar Assignee: Oleksandr Byelkin
Resolution: Unresolved Votes: 0
Labels: affects-tests, memory_not_freed, regression


 Description   

Could be an issue in the optimizer or in PS. Reproduces on MyISAM also, though the traces seem to include InnoDB code (even when MyISAM is used). The amount of memory loss grows accross releases (for optimized builds, 10.3 and 10.4 have 80 bytes lost, 10.5 and 10.6 have 104 bytes lost, 10.7 and 10.8 have 16400 bytes lost and 10.9 to 10.11 have 16424 bytes lost. Debug builds have different numbers)

CREATE TABLE t (c1 INT,c2 INT) ENGINE=InnoDB;
PREPARE s FROM 'WITH RECURSIVE d AS (SELECT * FROM t UNION ALL SELECT 1 FROM d) SELECT * FROM d AS e,d AS f';
SHUTDOWN;

Leads to:

10.3.37 a1055ab35d29437b717e83b1a388eaa02901c42f (Optimized)

2022-08-29 15:20:09 0 [Note] /test/MD200822-mariadb-10.3.37-linux-x86_64-opt/bin/mysqld: Shutdown complete
Warning: Memory not freed: 80

Same amount of memory (80 bytes) not freed on 10.4. However, on 10.5 we see:

10.5.18 5fc172fd43375b392a8c8adfb9038c279e578d83 (Optimized)

2022-08-29 15:25:00 0 [Note] /test/MD200822-mariadb-10.5.18-linux-x86_64-opt/bin/mysqld: Shutdown complete
Warning: Memory not freed: 104

10.5.18 5fc172fd43375b392a8c8adfb9038c279e578d83 (Debug)

Version: '10.5.18-MariaDB-debug'  socket: '/test/MD200822-mariadb-10.5.18-linux-x86_64-dbg/socket.sock'  port: 10798  MariaDB Server
2022-08-29 15:23:15 0 [Note] /test/MD200822-mariadb-10.5.18-linux-x86_64-dbg/bin/mysqld (initiated by: root[root] @ localhost []): Normal shutdown
2022-08-29 15:23:15 0 [Note] Event Scheduler: Purging the queue. 0 events
Warning: 1048 bytes lost at 0x564d8c330860, allocated by T@4 at 0x564d87ff4d8f, sql/sql_class.cc:891, handler/ha_innodb.cc:1473, fts/fts0opt.cc:2997, srv/srv0start.cc:1856, handler/ha_innodb.cc:4077, sql/handler.cc:645, sql/sql_plugin.cc:1461
Warning:  280 bytes lost at 0x564d8c328410, allocated by T@4 at mysys/array.c:71, mysys/hash.c:102, sql/sql_class.cc:856, sql/sql_class.cc:4988, handler/ha_innodb.cc:1473, fts/fts0opt.cc:2997, srv/srv0start.cc:1856, handler/ha_innodb.cc:4077
Warning:  280 bytes lost at 0x564d8c328270, allocated by T@4 at mysys/array.c:71, mysys/hash.c:102, sql/sql_class.cc:853, sql/sql_class.cc:4988, handler/ha_innodb.cc:1473, fts/fts0opt.cc:2997, srv/srv0start.cc:1856, handler/ha_innodb.cc:4077
Warning:  120 bytes lost at 0x564d8c2f7f80, allocated by T@4 at mysys/my_malloc.c:233, sql/session_tracker.cc:335, sql/sql_plugin.cc:3256, sql/sql_class.cc:1245, sql/sql_class.cc:848, sql/sql_class.cc:4988, handler/ha_innodb.cc:1473, fts/fts0opt.cc:2997
Warning: 1072 bytes lost at 0x564d8c327ba0, allocated by T@4 at mysys/my_alloc.c:80, sql/thr_malloc.cc:65, sql/sql_error.cc:523, sql/sql_class.cc:740, sql/sql_class.cc:4988, handler/ha_innodb.cc:1473, fts/fts0opt.cc:2997, srv/srv0start.cc:1856
Memory lost: 2800 bytes in 1016 chunks
mysqld: /test/10.5_dbg/sql/sql_class.cc:1744: virtual THD::~THD(): Assertion `status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory' failed.

Same amount of memory (104 bytes) not freed on 10.6. However, on 10.7 we see:

10.7.6 dc11fd07fdaf7316d340569f97a84fa0fd2d307e (Optimized)

2022-08-29 15:27:11 0 [Note] /test/MD200822-mariadb-10.7.6-linux-x86_64-opt/bin/mysqld: Shutdown complete
Warning: Memory not freed: 16400

10.7.6 dc11fd07fdaf7316d340569f97a84fa0fd2d307e (Debug)

2022-08-29 15:28:48 0 [Note] /test/MD200822-mariadb-10.7.6-linux-x86_64-dbg/bin/mysqld (initiated by: root[root] @ localhost []): Normal shutdown
Warning: 1048 bytes lost at 0x5562dc09cac0, allocated by T@4 at 0x5562d93f14b8, sql/sql_class.cc:895, handler/ha_innodb.cc:1816, fts/fts0opt.cc:2923, srv/srv0start.cc:1833, handler/ha_innodb.cc:4302, sql/handler.cc:649, sql/sql_plugin.cc:1464
Warning:  280 bytes lost at 0x5562dc09c920, allocated by T@4 at mysys/array.c:72, mysys/hash.c:102, sql/sql_class.cc:860, sql/sql_class.cc:4966, handler/ha_innodb.cc:1816, fts/fts0opt.cc:2923, srv/srv0start.cc:1833, handler/ha_innodb.cc:4302
Warning:  280 bytes lost at 0x5562dc09c780, allocated by T@4 at mysys/array.c:72, mysys/hash.c:102, sql/sql_class.cc:857, sql/sql_class.cc:4966, handler/ha_innodb.cc:1816, fts/fts0opt.cc:2923, srv/srv0start.cc:1833, handler/ha_innodb.cc:4302
Warning:  120 bytes lost at 0x5562dc0a4b90, allocated by T@4 at mysys/my_malloc.c:233, sql/session_tracker.cc:335, sql/sql_plugin.cc:3260, sql/sql_class.cc:1237, sql/sql_class.cc:852, sql/sql_class.cc:4966, handler/ha_innodb.cc:1816, fts/fts0opt.cc:2923
Memory lost: 1728 bytes in 1563 chunks
mysqld: /test/10.7_dbg/sql/sql_class.cc:1733: virtual THD::~THD(): Assertion `status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory' failed.

Same amount of memory (16400 bytes) not freed on 10.8. However, on 10.9 to 10.11 we see:

10.9.2 8cb75b9863a7043ebf2545158b3d2e634bca1831 (Optimized)

2022-08-29 15:29:51 0 [Note] /test/MD200822-mariadb-10.9.2-linux-x86_64-opt/bin/mysqld: Shutdown complete
Warning: Memory not freed: 16424

10.11.0 bc563f1a4b0b38de3b41fd0f0d3d8b7f1aacbd8b (Optimized)

2022-08-29 15:15:27 0 [Note] /test/MD190822-mariadb-10.11.0-linux-x86_64-opt/bin/mysqld: Shutdown complete
Warning: Memory not freed: 16424

10.11.0 bc563f1a4b0b38de3b41fd0f0d3d8b7f1aacbd8b (Debug)

2022-08-29 15:15:05 0 [Note] /test/MD190822-mariadb-10.11.0-linux-x86_64-dbg/bin/mysqld (initiated by: root[root] @ localhost []): Normal shutdown
Warning: 1048 bytes lost at 0x55ffcc0fe660, allocated by T@4 at 0x55ffc9f6d5de, sql/sql_class.cc:893, handler/ha_innodb.cc:1752, fts/fts0opt.cc:2923, srv/srv0start.cc:1543, handler/ha_innodb.cc:4233, sql/handler.cc:649, sql/sql_plugin.cc:1464
Warning:  280 bytes lost at 0x55ffcc0fe4c0, allocated by T@4 at mysys/array.c:72, mysys/hash.c:102, sql/sql_class.cc:858, sql/sql_class.cc:4965, handler/ha_innodb.cc:1752, fts/fts0opt.cc:2923, srv/srv0start.cc:1543, handler/ha_innodb.cc:4233
Warning:  280 bytes lost at 0x55ffcc0fe320, allocated by T@4 at mysys/array.c:72, mysys/hash.c:102, sql/sql_class.cc:855, sql/sql_class.cc:4965, handler/ha_innodb.cc:1752, fts/fts0opt.cc:2923, srv/srv0start.cc:1543, handler/ha_innodb.cc:4233
Warning:  120 bytes lost at 0x55ffcc106730, allocated by T@4 at mysys/my_malloc.c:233, sql/session_tracker.cc:335, sql/sql_plugin.cc:3260, sql/sql_class.cc:1235, sql/sql_class.cc:850, sql/sql_class.cc:4965, handler/ha_innodb.cc:1752, fts/fts0opt.cc:2923
Memory lost: 1728 bytes in 1553 chunks
mysqld: /test/10.11_dbg/sql/sql_class.cc:1731: virtual THD::~THD(): Assertion `status_var.local_memory_used == 0 || !debug_assert_on_not_freed_memory' failed.

Bug confirmed present in:
MariaDB: 10.3.37 (dbg), 10.3.37 (opt), 10.4.27 (dbg), 10.4.27 (opt), 10.5.18 (dbg), 10.5.18 (opt), 10.6.10 (dbg), 10.6.10 (opt), 10.7.6 (dbg), 10.7.6 (opt), 10.8.5 (dbg), 10.8.5 (opt), 10.9.2 (dbg), 10.9.2 (opt), 10.10.2 (dbg), 10.10.2 (opt), 10.11.0 (dbg), 10.11.0 (opt)

Bug (or feature/syntax) confirmed not present in:
MySQL: 5.5.62 (dbg), 5.5.62 (opt), 5.6.51 (dbg), 5.6.51 (opt), 5.7.38 (dbg), 5.7.38 (opt), 8.0.29 (dbg), 8.0.29 (opt)



 Comments   
Comment by Roel Van de Paar [ 2022-08-29 ]

Verified that this is not a new regression.
An earlier version (late 2021) of 10.8 yields 16320 bytes lost.

Comment by Roel Van de Paar [ 2022-08-29 ]

Discussed with Marko, unlikely to be in InnoDB.

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