| Bug #47808 | innodb_information_schema.test fails when run under valgrind | ||
|---|---|---|---|
| Submitted: | 4 Oct 2009 10:04 | Modified: | 19 Jun 2010 0:20 |
| Reporter: | Georgi Kodinov | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: InnoDB Plugin storage engine | Severity: | S3 (Non-critical) |
| Version: | 5.1+ | OS: | Linux (Fedora Core 11/x86_64) |
| Assigned to: | Satya B | CPU Architecture: | Any |
[4 Oct 2009 10:16]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/85664 3150 Georgi Kodinov 2009-10-04 Disable innodb_information_schema.test until bug #47808 is fixed.
[5 Oct 2009 15:43]
Vasil Dimov
This could be the reason for the failure: innodb_information_schema.test: 112 # Give time to the above 2 queries to execute before continuing. 113 # Without this sleep it sometimes happens that the SELECT from innodb_locks 114 # executes before some of them, resulting in less than expected number 115 # of rows being selected from innodb_locks. 116 -- sleep 0.1 Georgi, can you change the above to e.g. sleep 5 and see if the test passes? Thanks!
[6 Oct 2009 6:43]
Vasil Dimov
I confirm that the sleep 0.1 is the reason for the failure, changing it to sleep 20 results in no missing rows, which of course is not a solution to the problem with the timing.
[6 Oct 2009 7:03]
Sergey Vojtovich
Sleep is extremely fragile for the purpose of waiting for a condition. Some of the "wait" scripts should work here, see mysql-test/include/wait_*.inc
[6 Oct 2009 9:00]
Bugs System
Pushed into 5.1.40 (revid:joro@sun.com-20091006073316-lea2cpijh9r6on7c) (version source revid:joro@sun.com-20091004101553-vwri4yqps0nisb8y) (merge vers: 5.1.40) (pib:11)
[19 Oct 2009 12:56]
Vasil Dimov
Patch to fix this bug
Attachment: innodb_information_schema.test.diff (application/octet-stream, text), 1.21 KiB.
[19 Oct 2009 13:01]
Vasil Dimov
Here is a patch to fix this bug: http://bugs.mysql.com/file.php?id=13144 The patch uses the wait macros (thanks, Sergey!) I confirm that without this patch I get the error reported here and after applying the patch the error is gone. Btw there are some unrelated to this bug warnings produced: ./mysql-test-run --valgrind innodb_information_schema Logging: ./mysql-test-run --valgrind innodb_information_schema MySQL Version 5.1.41 Turning on valgrind for all executables Running valgrind with options " --show-reachable=yes " Checking supported features... - skipping ndbcluster, mysqld not compiled with ndbcluster - skipping SSL, mysqld not compiled with SSL Using "../libtool" when running valgrind or debugger Collecting tests... vardir: /tmp/mysql-5.1-checkout-lightweight/mysql-test/var Checking leftover processes... Removing old var directory... Creating var directory '/tmp/mysql-5.1-checkout-lightweight/mysql-test/var'... Installing system database... Using server port 42897 ============================================================================== TEST RESULT TIME (ms) ------------------------------------------------------------ worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009 innodb.innodb_information_schema [ skipped ] Test requires: 'true' innodb.innodb_information_schema 'InnoDB plugin' [ fail ] Found warnings/errors in server log file! Test ended at 2009-10-19 05:54:25 mysqltest: Logging to ''. mysqltest: Results saved in ''. mysqltest: Connecting to server localhost:13000 (socket /tmp/mysql-5.1-checkout-lightweight/mysql-test/var/tmp/mysqld.1.sock) as 'root', connection 'default', attempt 0 ... mysqltest: ... Connected. mysqltest: Start processing test commands from './include/check-warnings.test' ... file_name line /tmp/mysql-5.1-checkout-lightweight/mysql-test/var/log/mysqld.1.err ==7298== at 0x5A04E2D: rw_lock_x_lock_func (in /tmp/mysql-5.1-checkout-lightweight/storage/innodb_plugin/.libs/ha_innodb_plugin.so.0.0.0) /tmp/mysql-5.1-checkout-lightweight/mysql-test/var/log/mysqld.1.err ==7298== at 0x5A04E2D: rw_lock_x_lock_func (in /tmp/mysql-5.1-checkout-lightweight/storage/innodb_plugin/.libs/ha_innodb_plugin.so.0.0.0) /tmp/mysql-5.1-checkout-lightweight/mysql-test/var/log/mysqld.1.err ==7298== at 0x5A04FA8: rw_lock_x_lock_func (in /tmp/mysql-5.1-checkout-lightweight/storage/innodb_plugin/.libs/ha_innodb_plugin.so.0.0.0) /tmp/mysql-5.1-checkout-lightweight/mysql-test/var/log/mysqld.1.err ==7298== at 0x5A04FA8: rw_lock_x_lock_func (in /tmp/mysql-5.1-checkout-lightweight/storage/innodb_plugin/.libs/ha_innodb_plugin.so.0.0.0) ... /tmp/mysql-5.1-checkout-lightweight/mysql-test/var/log/mysqld.1.err ==7298== at 0x5A04E2D: rw_lock_x_lock_func (in /tmp/mysql-5.1-checkout-lightweight/storage/innodb_plugin/.libs/ha_innodb_plugin.so.0.0.0) ^ Found warnings!! mysqltest: ... Done processing test commands. mysqltest: Test has succeeded! ok - saving '/tmp/mysql-5.1-checkout-lightweight/mysql-test/var/log/innodb.innodb_information_schema-InnoDB plugin/' to '/tmp/mysql-5.1-checkout-lightweight/mysql-test/var/log/innodb.innodb_information_schema-InnoDB plugin/' ------------------------------------------------------------ The servers were restarted 1 times Spent 0.000 of 25 seconds executing testcases mysql-test-run: WARNING: Got errors/warnings while running tests, please examine '/tmp/mysql-5.1-checkout-lightweight/mysql-test/var/log/warnings' for details. Failed 1/1 tests, 0.00% were successful. Failing test(s): innodb.innodb_information_schema The log files in var/log may give you some hint of what went wrong.
[22 Oct 2009 6:35]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091022063126-l0qzirh9xyhp0bpc) (version source revid:alik@sun.com-20091019135554-s1pvptt6i750lfhv) (merge vers: 6.0.14-alpha) (pib:13)
[22 Oct 2009 7:07]
Bugs System
Pushed into 5.5.0-beta (revid:alik@sun.com-20091022060553-znkmxm0g0gm6ckvw) (version source revid:alik@sun.com-20091013094238-g67x6tgdm9a7uik0) (merge vers: 5.5.0-beta) (pib:13)
[4 Nov 2009 9:25]
Bugs System
Pushed into 5.1.41 (revid:joro@sun.com-20091104092152-qz96bzlf2o1japwc) (version source revid:kristofer.pettersson@sun.com-20091103162305-08l4gkeuif2ozsoj) (merge vers: 5.1.41) (pib:13)
[11 Nov 2009 6:50]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091110093407-rw5g8dys2baqkt67) (version source revid:alik@sun.com-20091109080109-7dxapd5y5pxlu08w) (merge vers: 6.0.14-alpha) (pib:13)
[11 Nov 2009 6:58]
Bugs System
Pushed into 5.5.0-beta (revid:alik@sun.com-20091109115615-nuohp02h8mdrz8m2) (version source revid:svoj@sun.com-20091105122958-jyqjx9xus8v4e0yd) (merge vers: 5.5.0-beta) (pib:13)
[22 Nov 2009 0:27]
Paul DuBois
Changes to test case. No changelog entry needed.
[18 Dec 2009 10:33]
Bugs System
Pushed into 5.1.41-ndb-7.1.0 (revid:jonas@mysql.com-20091218102229-64tk47xonu3dv6r6) (version source revid:jonas@mysql.com-20091218095730-26gwjidfsdw45dto) (merge vers: 5.1.41-ndb-7.1.0) (pib:15)
[18 Dec 2009 10:49]
Bugs System
Pushed into 5.1.41-ndb-6.2.19 (revid:jonas@mysql.com-20091218100224-vtzr0fahhsuhjsmt) (version source revid:jonas@mysql.com-20091217101452-qwzyaig50w74xmye) (merge vers: 5.1.41-ndb-6.2.19) (pib:15)
[18 Dec 2009 11:04]
Bugs System
Pushed into 5.1.41-ndb-6.3.31 (revid:jonas@mysql.com-20091218100616-75d9tek96o6ob6k0) (version source revid:jonas@mysql.com-20091217154335-290no45qdins5bwo) (merge vers: 5.1.41-ndb-6.3.31) (pib:15)
[18 Dec 2009 11:18]
Bugs System
Pushed into 5.1.41-ndb-7.0.11 (revid:jonas@mysql.com-20091218101303-ga32mrnr15jsa606) (version source revid:jonas@mysql.com-20091218064304-ezreonykd9f4kelk) (merge vers: 5.1.41-ndb-7.0.11) (pib:15)
[5 May 2010 15:16]
Bugs System
Pushed into 5.1.47 (revid:joro@sun.com-20100505145753-ivlt4hclbrjy8eye) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[6 May 2010 17:17]
Paul DuBois
Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug. Re-closing.
[28 May 2010 6:02]
Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100524190136-egaq7e8zgkwb9aqi) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (pib:16)
[28 May 2010 6:31]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20100524190941-nuudpx60if25wsvx) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[28 May 2010 6:59]
Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100524185725-c8k5q7v60i5nix3t) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[30 May 2010 0:17]
Paul DuBois
Push resulted from incorporation of InnoDB tree. No changes pertinent to this bug. Re-closing.
[15 Jun 2010 8:15]
Bugs System
Pushed into 5.5.5-m3 (revid:alik@sun.com-20100615080459-smuswd9ooeywcxuc) (version source revid:mmakela@bk-internal.mysql.com-20100415070122-1nxji8ym4mao13ao) (merge vers: 5.1.47) (pib:16)
[15 Jun 2010 8:32]
Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20100615080558-cw01bzdqr1bdmmec) (version source revid:mmakela@bk-internal.mysql.com-20100415070122-1nxji8ym4mao13ao) (pib:16)
[17 Jun 2010 12:06]
Bugs System
Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 12:51]
Bugs System
Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
[17 Jun 2010 13:33]
Bugs System
Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)
Description: Innodb_information_schema.test fails for innodb plugin when run under valgrind as follows : innodb.innodb_information_schema 'InnoDB plugin' w8 [ fail ] Test ended at 2009-10-02 23:50:30 CURRENT_TEST: innodb.innodb_information_schema ==30753== Memcheck, a memory error detector. ==30753== Copyright (C) 2002-2006, and GNU GPL'd, by Julian Seward et al. ==30753== Using LibVEX rev 1658, a library for dynamic binary translation. ==30753== Copyright (C) 2004-2006, and GNU GPL'd, by OpenWorks LLP. ==30753== Using valgrind-3.2.1, a dynamic binary instrumentation framework. ==30753== Copyright (C) 2000-2006, and GNU GPL'd, by Julian Seward et al. ==30753== For more details, rerun with: -v ==30753== --- /export/home/pb2/test/sb_1-787728-1254519012.52/mysql-5.1.40-linux-x86_64-test/mysql-test/suite/innodb/r/innodb_information_schema.result 2009-10-02 16:42:34.000000000 +0300 +++ /export/home/pb2/test/sb_1-787728-1254519012.52/mysql-5.1.40-linux-x86_64-test/mysql-test/suite/innodb/r/innodb_information_schema.reject 2009-10-03 00:50:29.000000000 +0300 @@ -1,18 +1,8 @@ lock_mode lock_type lock_table lock_index lock_rec lock_data -X RECORD `test`.```t'\"_str` `PRIMARY` 2 '1', 'abc', '''abc', 'abc''', 'a''bc', 'a''bc''', '''abc''''' -X RECORD `test`.```t'\"_str` `PRIMARY` 2 '1', 'abc', '''abc', 'abc''', 'a''bc', 'a''bc''', '''abc''''' -X RECORD `test`.```t'\"_str` `PRIMARY` 3 '2', 'abc', '"abc', 'abc"', 'a"bc', 'a"bc"', '"abc""' -X RECORD `test`.```t'\"_str` `PRIMARY` 3 '2', 'abc', '"abc', 'abc"', 'a"bc', 'a"bc"', '"abc""' -X RECORD `test`.```t'\"_str` `PRIMARY` 4 '3', 'abc', '\\abc', 'abc\\', 'a\\bc', 'a\\bc\\', '\\abc\\\\' -X RECORD `test`.```t'\"_str` `PRIMARY` 4 '3', 'abc', '\\abc', 'abc\\', 'a\\bc', 'a\\bc\\', '\\abc\\\\' X RECORD `test`.```t'\"_str` `PRIMARY` 5 '4', 'abc', '\0abc', 'abc\0', 'a\0bc', 'a\0bc\0', 'a\0bc\0\0' X RECORD `test`.```t'\"_str` `PRIMARY` 5 '4', 'abc', '\0abc', 'abc\0', 'a\0bc', 'a\0bc\0', 'a\0bc\0\0' X RECORD `test`.`t_min` `PRIMARY` 2 -128, 0, -32768, 0, -8388608, 0, -2147483648, 0, -9223372036854775808, 0 X RECORD `test`.`t_min` `PRIMARY` 2 -128, 0, -32768, 0, -8388608, 0, -2147483648, 0, -9223372036854775808, 0 -X RECORD `test`.`t_max` `PRIMARY` 2 127, 255, 32767, 65535, 8388607, 16777215, 2147483647, 4294967295, 9223372036854775807, 18446744073709551615 -X RECORD `test`.`t_max` `PRIMARY` 2 127, 255, 32767, 65535, 8388607, 16777215, 2147483647, 4294967295, 9223372036854775807, 18446744073709551615 -X RECORD `test`.```t'\"_str` `PRIMARY` 1 supremum pseudo-record -X RECORD `test`.```t'\"_str` `PRIMARY` 1 supremum pseudo-record lock_table COUNT(*) `test`.`t_max` 2 `test`.`t_min` 2 mysqltest: Result content mismatch ==30753== ==30753== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 4 from 1) ==30753== malloc/free: in use at exit: 344 bytes in 10 blocks. ==30753== malloc/free: 1,055 allocs, 1,045 frees, 518,825 bytes allocated. ==30753== For counts of detected errors, rerun with: -v ==30753== searching for pointers to 10 not-freed blocks. ==30753== checked 2,294,848 bytes. ==30753== ==30753== 32 bytes in 1 blocks are still reachable in loss record 1 of 3 ==30753== at 0x4A0590B: realloc (vg_replace_malloc.c:306) ==30753== by 0x4661B4: my_realloc (my_realloc.c:62) ==30753== by 0x46D0B5: dynstr_append_mem (string.c:106) ==30753== by 0x452F58: do_eval(st_dynamic_string*, char const*, char const*, char) (mysqltest.cc:798) ==30753== by 0x453851: check_command_args(st_command*, char const*, command_arg const*, int, char) (mysqltest.cc:996) ==30753== by 0x45659C: do_close_connection(st_command*) (mysqltest.cc:4645) ==30753== by 0x458B2F: main (mysqltest.cc:7740) { <insert a suppression name here> Memcheck:Leak fun:_vgrZU_libcZdsoZa_realloc fun:my_realloc fun:dynstr_append_mem fun:_Z7do_evalP17st_dynamic_stringPKcS2_c fun:_Z18check_command_argsP10st_commandPKcPK11command_argic fun:_Z19do_close_connectionP10st_command fun:main } ==30753== ==30753== ==30753== 256 bytes in 8 blocks are definitely lost in loss record 3 of 3 ==30753== at 0x4A0590B: realloc (vg_replace_malloc.c:306) ==30753== by 0x4661B4: my_realloc (my_realloc.c:62) ==30753== by 0x46D0B5: dynstr_append_mem (string.c:106) ==30753== by 0x452F58: do_eval(st_dynamic_string*, char const*, char const*, char) (mysqltest.cc:798) ==30753== by 0x453851: check_command_args(st_command*, char const*, command_arg const*, int, char) (mysqltest.cc:996) ==30753== by 0x45659C: do_close_connection(st_command*) (mysqltest.cc:4645) ==30753== by 0x458B2F: main (mysqltest.cc:7740) { <insert a suppression name here> Memcheck:Leak fun:_vgrZU_libcZdsoZa_realloc fun:my_realloc fun:dynstr_append_mem fun:_Z7do_evalP17st_dynamic_stringPKcS2_c fun:_Z18check_command_argsP10st_commandPKcPK11command_argic fun:_Z19do_close_connectionP10st_command fun:main } ==30753== ==30753== LEAK SUMMARY: ==30753== definitely lost: 256 bytes in 8 blocks. ==30753== possibly lost: 0 bytes in 0 blocks. ==30753== still reachable: 32 bytes in 1 blocks. ==30753== suppressed: 56 bytes in 1 blocks. How to repeat: Compile with valgrind and run ./mysql-test-run --valgrind innodb_information_schema.test Suggested fix: "cure" the valgrind warnings