Elena Stepanova added a comment - 2019-10-06 15:38 matze , First of all, could you please specify how much memory your machine has, and how much (approximately) is "vast amounts of memory"? Further, I'm not sure I quite understand, does it or does it not work on 10.1? First you said > Then I tried to run the same command on our test system with an older version of MariaDB (10.1.25), but with the same data, events, triggers and routines as the slave. It crashed. but then > Before the upgrade, everything worked fine on the slave and the (older) test system. So which is it, does it work fine or does it crash? And yes, sure, please attach your massif output. Please also paste or attach your config file(s). If you can provide the actual dump on which the problem is reproducible, it would be even better. You can upload it to ftp.askmonty.org/private if you don't want to make it public.

Matthias added a comment - 2019-10-10 14:51 Hi @Elena, thank you for your answer! All of our servers had 2 GB of memory in total. I know, this sounds few, but it worked for more than 9 months. Now, our test server still has 2 GB, while the other (productive) servers have 4 to 10 GB. I'm not sure if I interpret the results from valgrind and massif correctly, but it looks like MariaDB allocates about 80 MB per stored procedure (and never releases the memory again). As we have 422 stored procedures, that would make about 33 GB in total. I'm sorry, I must have expressed myself somewhat inaccurately. We have 3 productive nodes: one master and two slaves. Node 1 (master) is version 10.3.17, node 2 (first slave) is 10.4.8 and node 3 (second slave) is 10.3.17 too. Before the update, all servers had version 10.1.25 (like the test system right now). Every night at 10 pm, an automatic full backup using mysqldump was created from one of the slaves, including events, triggers and routines. Also, to keep the test system up-to-date, a dump was created at 9 pm from node 2 and imported into the test system. So creating a full dump or backup from one of these servers (all 10.1.25) was no problem. But since the update, when dumping the routines on the slave (no matter if locally or remotely) the server runs out of memory within a few seconds and gets killed. And it's since this update that even the test system runs out of memory, even though it's still 10.1.25. That's what's so confusing to us. I'm afraid I can't provide the actual dump because it has 3 GB in size, but maybe I can provide one single stored procedure, so you can test it and see if it's the stored procedure that causes this issue. But actually it looks like that all stored procedures are affected, not only one single or maybe a couple... I will provide the massif output and the config file. By the way: I'm on vacation next week, so please don't be mad at me if I don't answer. But I'll be back on October 21st. Thank you and regards, Matthias

Oleksandr Byelkin added a comment - 2020-03-25 11:26 What about test suite?

Vladislav Vaintroub added a comment - 2021-09-25 23:18 - edited I can't reproduce with current 10.3 (I did not test any earlier versions, since I understand, it is not used be the reporter). Here is the full session with valgrind and mysqldump of the database netmon (routines in the attachment use that database). Valgrind report 288 bytes leaked in allocating tls variable somewhere, but I'm sure this is something on libc account, not on ours. In other words, there is no leak. It reports however 1GB memory use, which I believe is fine. wlad@workpc:~/10.4/xxx/sql$ valgrind --leak-check=full ./mysqld --datadir=/home/wlad/10.4/xxx/sql/data & [1] 10737 wlad@workpc:~/10.4/xxx/sql$ ==10737== Memcheck, a memory error detector ==10737== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al. ==10737== Using Valgrind-3.14.0 and LibVEX; rerun with -h for copyright info ==10737== Command: ./mysqld --datadir=/home/wlad/10.4/xxx/sql/data ==10737== 2021-09-26 1:09:14 0 [Note] ./mysqld (mysqld 10.3.32-MariaDB) starting as process 10737 ... 2021-09-26 1:09:14 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32190) 2021-09-26 1:09:14 0 [Warning] Changed limits: max_open_files: 1024 max_connections: 151 (was 151) table_cache: 421 (was 2000) 2021-09-26 1:09:15 0 [Note] InnoDB: Using Linux native AIO 2021-09-26 1:09:15 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins 2021-09-26 1:09:15 0 [Note] InnoDB: Uses event mutexes 2021-09-26 1:09:15 0 [Note] InnoDB: Compressed tables use zlib 1.2.11 2021-09-26 1:09:15 0 [Note] InnoDB: Number of pools: 1 2021-09-26 1:09:15 0 [Note] InnoDB: Using SSE2 crc32 instructions 2021-09-26 1:09:15 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M 2021-09-26 1:09:15 0 [Note] InnoDB: Completed initialization of buffer pool 2021-09-26 1:09:16 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority(). 2021-09-26 1:09:16 0 [Note] InnoDB: 128 out of 128 rollback segments are active. 2021-09-26 1:09:16 0 [Note] InnoDB: Creating shared tablespace for temporary tables 2021-09-26 1:09:16 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ... 2021-09-26 1:09:16 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB. 2021-09-26 1:09:16 0 [Note] InnoDB: Waiting for purge to start 2021-09-26 1:09:17 0 [Note] InnoDB: 10.3.32 started; log sequence number 1625479; transaction id 20 2021-09-26 1:09:17 0 [Note] InnoDB: Loading buffer pool(s) from /home/wlad/10.4/xxx/sql/data/ib_buffer_pool 2021-09-26 1:09:17 0 [Note] InnoDB: Buffer pool(s) load completed at 210926 1:09:17 2021-09-26 1:09:17 0 [Note] Plugin 'FEEDBACK' is disabled. 2021-09-26 1:09:17 0 [Note] Server socket created on IP: '::'. 2021-09-26 1:09:17 0 [Note] Reading of all Master_info entries succeeded 2021-09-26 1:09:17 0 [Note] Added new Master_info '' to hash table 2021-09-26 1:09:17 0 [Note] ./mysqld: ready for connections. Version: '10.3.32-MariaDB' socket: '/tmp/mysql.sock' port: 3306 Source distribution   wlad@workpc:~/10.4/xxx/sql$ ../client/mysqldump -uroot --routines netmon --protocol=tcp > dump.out wlad@workpc:~/10.4/xxx/sql$ ls -l dump.out -rw-r--r-- 1 wlad wlad 3966721 Sep 26 01:10 dump.out wlad@workpc:~/10.4/xxx/sql$ ../client/mysql -uroot -e shutdown wlad@workpc:~/10.4/xxx/sql$ 2021-09-26 1:11:20 0 [Note] ./mysqld (initiated by: root[root] @ localhost []): Normal shutdown 2021-09-26 1:11:20 0 [Note] Event Scheduler: Purging the queue. 0 events 2021-09-26 1:11:20 0 [Note] InnoDB: FTS optimize thread exiting. 2021-09-26 1:13:36 0 [Note] InnoDB: Starting shutdown... 2021-09-26 1:13:36 0 [Note] InnoDB: Dumping buffer pool(s) to /home/wlad/10.4/xxx/sql/data/ib_buffer_pool 2021-09-26 1:13:36 0 [Note] InnoDB: Buffer pool(s) dump completed at 210926 1:13:36 2021-09-26 1:13:39 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1" 2021-09-26 1:13:39 0 [Note] InnoDB: Shutdown completed; log sequence number 1625488; transaction id 21 2021-09-26 1:13:39 0 [Note] ./mysqld: Shutdown complete   ==10737== ==10737== HEAP SUMMARY: ==10737== in use at exit: 288 bytes in 1 blocks ==10737== total heap usage: 57,614 allocs, 57,613 frees, 1,066,096,426 bytes allocated ==10737== ==10737== 288 bytes in 1 blocks are possibly lost in loss record 1 of 1 ==10737== at 0x4837B65: calloc (vg_replace_malloc.c:752) ==10737== by 0x40116D1: allocate_dtv (dl-tls.c:286) ==10737== by 0x401203D: _dl_allocate_tls (dl-tls.c:532) ==10737== by 0x5157B95: allocate_stack (allocatestack.c:621) ==10737== by 0x5157B95: pthread_create@@GLIBC_2.2.5 (pthread_create.c:669) ==10737== by 0x87A066: inline_mysql_thread_create (mysql_thread.h:1275) ==10737== by 0x87A066: innodb_init(void*) (ha_innodb.cc:4316) ==10737== by 0x71B322: ha_initialize_handlerton(st_plugin_int*) (handler.cc:549) ==10737== by 0x5612DA: plugin_initialize(st_mem_root*, st_plugin_int*, int*, char**, bool) (sql_plugin.cc:1433) ==10737== by 0x562409: plugin_init(int*, char**, int) (sql_plugin.cc:1715) ==10737== by 0x4A5CB1: init_server_components() (mysqld.cc:5467) ==10737== by 0x4AC6A4: mysqld_main(int, char**) (mysqld.cc:6087) ==10737== by 0x519409A: (below main) (libc-start.c:308) ==10737== ==10737== LEAK SUMMARY: ==10737== definitely lost: 0 bytes in 0 blocks ==10737== indirectly lost: 0 bytes in 0 blocks ==10737== possibly lost: 288 bytes in 1 blocks ==10737== still reachable: 0 bytes in 0 blocks ==10737== suppressed: 0 bytes in 0 blocks ==10737== ==10737== For counts of detected and suppressed errors, rerun with: -v ==10737== ERROR SUMMARY: 1 errors from 1 contexts (suppressed: 0 from 0)   [1]+ Done valgrind --leak-check=full ./mysqld --datadir=/home/wlad/10.4/xxx/sql/data However, in terms of virtual memory, pmap shows about 500MB more usage, which does not grow if dump is repeated wlad@workpc:~/10.4/xxx/sql$ pmap `pidof mysqld` |grep total total 1760496K wlad@workpc:~/10.4/xxx/sql$ ../client/mysqldump -uroot --routines netmon --protocol=tcp > dump.out wlad@workpc:~/10.4/xxx/sql$ pmap `pidof mysqld` |grep total total 2350320K wlad@workpc:~/10.4/xxx/sql$ ../client/mysqldump -uroot --routines netmon --protocol=tcp > dump.out wlad@workpc:~/10.4/xxx/sql$ pmap `pidof mysqld` |grep total total 2350320K That thing is the supposedly libc heap growth, and whether it is possible to ever get this memory back, and whether it is possible to force it to allocate less, or maybe there is a more compact allocator, I do not really know. So, matze , is there still a problem we need to investigate? maybe you can try some recent version of mariadb, and be happy with results.

Vladislav Vaintroub added a comment - 2021-09-27 11:28 - edited Alright, of course the routines to be dumped are parsed for SHOW CREATE PROCEDURE, and stored in a per-connection cache , which is a problem for mysqldump, if there is a lot of routines, and they are large. For the 80 stored procedures, found in Memory measurement.zip , I measured the overhead of SHOW CREATE, using umdh tool, on Windows. The raw data is in umdh.zip , also containing callstacks of the allocation. The measurement is taken for the loop in mysqldump, that does "SHOW CREATE PROCEDURE". Note, that some of those procedures do not work in 10.4 (server would complain about undeclared in_User variable). I think that a workaround, for matze would be to SET GLOBAL stored_program_cache=1, at least for duration of mysqldump. And a fix for this case, would be to bypass caching stored procedures in SHOW CREATE - the very reason for cache is to speedup SP execution, so caching during the execution only should be fine. And a general remark, since this per-connection cache can grow almost uncontrollably, and SP can easily take several MB, maybe the decision on whether to cache, should not be based on number of stored procedures, but on size, in bytes, of parsed SPs.

Vladislav Vaintroub added a comment - 2021-09-27 15:48 - edited sanja , please review bb-10.3-wlad- MDEV-20699

Oleksandr Byelkin added a comment - 2021-09-28 12:04 OK to push