[MDEV-9105] Test failures under valgrind Created: 2015-11-09  Updated: 2017-05-09  Resolved: 2017-05-09

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.1.8
Fix Version/s: 10.1.17

Type: Bug Priority: Major
Reporter: Nirbhay Choubey (Inactive) Assignee: Marko Mäkelä
Resolution: Fixed Votes: 0
Labels: None
Environment:

amd64, valgrind

Issue Links:
Blocks
blocks MDEV-7069 Fix buildbot failures in main server ... Stalled
Relates
relates to MDEV-11601 Out-of-bounds string access in create... Closed
relates to MDEV-11602 InnoDB leaks foreign key metadata on ... Closed
Sprint: 10.2.1-5

 Description   

http://buildbot.askmonty.org/buildbot/builders/work-amd64-valgrind/builds/7841/steps/test/logs/stdio

encryption.innodb-bad-key-shutdown 'innodb_plugin' w6 [ fail ]  Found warnings/errors in server log file!
 
        Test ended at 2015-11-07 18:22:29
 
line
 
==21531== 163 bytes in 1 blocks are still reachable in loss record 3 of 3
 
==21531==    at 0x4C25FE6: realloc (vg_replace_malloc.c:662)
 
==21531==    by 0x62936C7: vasprintf (in /lib64/libc-2.9.so)
 
==21531==    by 0x6273707: asprintf (in /lib64/libc-2.9.so)
 
==21531==    by 0x58A959E: dlerror (in /lib64/libdl-2.9.so)
 
==21531==    by 0x61BEB0: plugin_dl_add(st_mysql_lex_string const*, int) (sql_plugin.cc:762)
 
==21531==    by 0x61C1E2: plugin_add(st_mem_root*, st_mysql_lex_string const*, st_mysql_lex_string*, int) (sql_plugin.cc:1086)
 
==21531==    by 0x620032: plugin_init(int*, char**, int) (sql_plugin.cc:1884)
 
==21531==    by 0x552474: init_server_components() (mysqld.cc:5204)
 
==21531==    by 0x553A74: mysqld_main(int, char**) (mysqld.cc:5806)
 
==21531==    by 0x6244585: (below main) (in /lib64/libc-2.9.so)
 
==21588== 163 bytes in 1 blocks are still reachable in loss record 3 of 3
 
==21588==    at 0x4C25FE6: realloc (vg_replace_malloc.c:662)
 
==21588==    by 0x62936C7: vasprintf (in /lib64/libc-2.9.so)
 
==21588==    by 0x6273707: asprintf (in /lib64/libc-2.9.so)
 
==21588==    by 0x58A959E: dlerror (in /lib64/libdl-2.9.so)
 
==21588==    by 0x61BEB0: plugin_dl_add(st_mysql_lex_string const*, int) (sql_plugin.cc:762)
 
==21588==    by 0x61C1E2: plugin_add(st_mem_root*, st_mysql_lex_string const*, st_mysql_lex_string*, int) (sql_plugin.cc:1086)
 
==21588==    by 0x620032: plugin_init(int*, char**, int) (sql_plugin.cc:1884)
 
==21588==    by 0x552474: init_server_components() (mysqld.cc:5204)
 
==21588==    by 0x553A74: mysqld_main(int, char**) (mysqld.cc:5806)
 
==21588==    by 0x6244585: (below main) (in /lib64/libc-2.9.so)
 
^ Found warnings in /mnt/data/buildot/maria-slave/work-opensuse-amd64/build/mysql-test/var/6/log/mysqld.1.err
 
ok
 

innodb.innodb-bug-14068765 'innodb_plugin' w6 [ fail ]
 
        Test ended at 2015-11-07 18:35:12
 
 
 
CURRENT_TEST: innodb.innodb-bug-14068765
 
mysqltest: At line 62: query 'ALTER TABLE testdb_wl5522.t1 IMPORT TABLESPACE' failed: 2013: Lost connection to MySQL server during query
 
.. cut ..
 
2015-11-07 18:35:10 68245840 [Note] InnoDB: Phase I - Update all pages
 
2015-11-07 18:35:10 4115950  InnoDB: Assertion failure in thread 68245840 in file buf0buf.ic line 271
 
InnoDB: Failing assertion: state == BUF_BLOCK_NOT_USED || state == BUF_BLOCK_REMOVE_HASH
 
InnoDB: We intentionally generate a memory trap.
 
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
 
InnoDB: If you get repeated assertion failures or crashes, even
 
InnoDB: immediately after the mysqld startup, there may be
 
InnoDB: corruption in the InnoDB tablespace. Please refer to
 
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
 
InnoDB: about forcing recovery.
 
151107 18:35:10 [ERROR] mysqld got signal 6 ;
 
This could be because you hit a bug. It is also possible that this binary
 
or one of the libraries it was linked against is corrupt, improperly built,
 
or misconfigured. This error can also be caused by malfunctioning hardware.
 
 
 
To report this bug, see http://kb.askmonty.org/en/reporting-bugs
 
 
 
We will try our best to scrape up some info that will hopefully help
 
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
 
 
Server version: 10.1.9-MariaDB-valgrind-max-debug-log
 
key_buffer_size=1048576
 
read_buffer_size=131072
 
max_used_connections=3
 
max_threads=153
 
thread_count=1
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 63009 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x0x1694f4d8
 
Attempting backtrace. You can use the following information to find out
 
where mysqld died. If you see no messages after this, something went
 
terribly wrong...
 
stack_bottom = 0x4115078 thread_stack 0x48000
 
mysys/stacktrace.c:247(my_print_stacktrace)[0xe893fe]
 
sql/signal_handler.cc:160(handle_fatal_signal)[0x7f144a]
 
/lib64/libpthread.so.0[0x4e3ca90]
 
/lib64/libc.so.6(gsignal+0x35)[0x6258645]
 
/lib64/libc.so.6(abort+0x183)[0x6259c33]
 
/mnt/data/buildot/maria-slave/work-opensuse-amd64/build/mysql-test/var/6/plugins/ha_innodb.so[0xb6bf73d]
 
/mnt/data/buildot/maria-slave/work-opensuse-amd64/build/mysql-test/var/6/plugins/ha_innodb.so[0xb6c29d8]
 
/mnt/data/buildot/maria-slave/work-opensuse-amd64/build/mysql-test/var/6/plugins/ha_innodb.so[0xb7dee0d]
 
/mnt/data/buildot/maria-slave/work-opensuse-amd64/build/mysql-test/var/6/plugins/ha_innodb.so[0xb720868]
 
sql/sql_class.h:2016(THD::enter_stage(PSI_stage_info_v1 const*, char const*, char const*, unsigned int))[0x6ad3c9]
 
sql/sql_alter.cc:365(Sql_cmd_discard_import_tablespace::execute(THD*))[0x710b77]
 
sql/sql_parse.cc:5642(mysql_execute_command(THD*))[0x60a02b]
 
sql/sql_parse.cc:7265(mysql_parse(THD*, char*, unsigned int, Parser_state*))[0x611a9b]
 
sql/sql_parse.cc:1488(dispatch_command(enum_server_command, THD*, char*, unsigned int))[0x614e60]
 
sql/sql_parse.cc:1110(do_command(THD*))[0x615453]
 
sql/sql_connect.cc:1350(do_handle_one_connection(THD*))[0x70d21c]
 
sql/sql_connect.cc:1264(handle_one_connection)[0x70d3c5]
 
perfschema/pfs.cc:1863(pfs_spawn_thread)[0xb988a7]
 
/lib64/libpthread.so.0[0x4e35070]
 
/lib64/libc.so.6(clone+0x6d)[0x62f913d]



 Comments   
Comment by Jan Lindström (Inactive) [ 2015-11-11 ]

Not sure how to repeat exactly the same warnings/errors I see different ones and can't repeat that crash, any advice ?

Comment by Nirbhay Choubey (Inactive) [ 2015-11-11 ]

jplindst Hi! I just noticed these failures on buildbot. Haven't personally tried them.

Comment by Elena Stepanova [ 2016-07-24 ]

Suddenly there are many more of the same kind as innodb.innodb-bug-14068765 above:
http://buildbot.askmonty.org/buildbot/builders/work-amd64-valgrind/builds/9079/steps/test/logs/stdio

  • innodb.innodb-bug-14084530
  • innodb.innodb-wl5522-1
  • innodb.innodb-wl5522-zip
  • innodb.innodb-wl5522
    Also
  • innodb.innodb-page_compression_zip
Comment by Marko Mäkelä [ 2017-01-30 ]

Is this still repeatable? 10.1 built -DWITH_ASAN does not generate any LeakSanitizer warnings for me any more. Recent fixes include these:

commit 78e6fafcaa93bdd2cf793a82a812137eb7a779a7
 
Author: Marko Mäkelä <marko.makela@mariadb.com>
 
Date:   Tue Jan 10 14:11:32 2017 +0200
 
 
 
    Fix an innodb_plugin leak noted in MDEV-11686
 
    
    buf_flush_init_flush_rbt() was called too early in MariaDB server 10.0,
 
    10.1, MySQL 5.5 and MySQL 5.6. The memory leak has been fixed in
 
    the XtraDB storage engine and in MySQL 5.7.
 
    
    As a result, when the server is started to initialize new data files,
 
    the buf_pool->flush_rbt will be created unnecessarily and then leaked.
 
    This memory leak was noticed in MariaDB server 10.1 when running the
 
    test encryption.innodb_first_page.
 
 
 
commit f0c19b6a57b699d113e3ae4a67920924bbecae45
 
Author: Marko Mäkelä <marko.makela@mariadb.com>
 
Date:   Thu Jan 5 20:13:34 2017 +0200
 
 
 
    MDEV-11730 Memory leak in innodb.innodb_corrupt_bit
 
…
 
 
 
commit fb5ee7d6d043b01fabc59f09d70d532e843add60
 
Author: Marko Mäkelä <marko.makela@mariadb.com>
 
Date:   Thu Jan 5 19:01:14 2017 +0200
 
 
 
    Plug a memory leak in buf_dblwr_process().

Comment by Marko Mäkelä [ 2017-01-31 ]

I found that in 10.2, a memory leak was introduced to ut_allocator::deallocate() in a merge:

commit fec844aca88e1c6b9c36bb0b811e92d9d023ffb9
 
Author: Jan Lindström <jan.lindstrom@mariadb.com>
 
Date:   Tue Sep 6 09:43:16 2016 +0300
 
 
 
    Merge InnoDB 5.7 from mysql-5.7.14.

With -DWITH_ASAN some leaks were reported already for the server bootstrap.
The above merge commit is commenting out the free(ptr) call in ut_allocator::deallocate(), introducing memory leaks to anything that uses ut_allocator in InnoDB. The last change to ut0new.h in MySQL 5.7 as of this writing is a change by me on 2015-11-10. That change was part of the above merge.
It looks like the ut_free() call may have been temporarily commented out to test something while the merge was being worked on. With that change reverted, the leaks are gone, and ASAN only seems to hit MDEV-11601 in 10.2 (the fix has not been merged from 10.1 yet).

Comment by Marko Mäkelä [ 2017-02-01 ]

In MariaDB Server 10.2.4, InnoDB should no longer leak memory (according to WITH_ASAN on GCC 6.3.0) even after an aborted plugin startup.

commit 81b7fe9d383bdf68a622b95384f067ed68ba342c
 
Author: Marko Mäkelä <marko.makela@mariadb.com>
 
Date:   Tue Jan 31 19:43:03 2017 +0200
 
 
 
    Shut down InnoDB after aborted startup.
 
    
    This fixes memory leaks in tests that cause InnoDB startup to fail.

With some effort, we could backport this to 10.1 if we wanted to plug this class of memory leaks.

Comment by Elena Stepanova [ 2017-05-09 ]

The described Valgrind warnings stopped appearing in buildbot since 2016-09-09 (on 10.2), and earlier on older versions.
The assertion failure was last observed on 2016-09-13 (on 10.2), earlier on older versions.
Before that, both were happening regularly.
So, I think it can be safely closed.

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