Bug #47612 mtr - improving the report for valgrind erorrs
Submitted: 24 Sep 2009 13:54 Modified: 18 Dec 2009 23:46
Reporter: Magnus Blåudd Email Updates:
Status: Closed Impact on me:
None 
Category:Tools: MTR / mysql-test-run Severity:S4 (Feature request)
Version:5.1.37 OS:Any
Assigned to: Magnus Blåudd CPU Architecture:Any

[24 Sep 2009 13:54] Magnus Blåudd
Description:

The report for the errors detected by valgrind have seen better days.  :( 

Currently it looks like:

file_name    line
/dev/shm/var-test-80/2/log/mysqld.1.1.err    ==5109==    at 0x4C216AB: 
malloc (in /usr/lib64/valgrind/amd64-linux/vgpreload_memcheck.so)
^ Found warnings!!

Have written a patch that improves the report and get the full valgrind 
report printed(not the same error but one get the idea):

==27244== Thread 20:

==27244== Source and destination overlap in memcpy(0x5DBB6B8, 0x5DBB6B8, 28)

==27244==    at 0x4A0A4DA: memcpy (mc_replace_strmem.c:402)

==27244==    by 0x683F3C: JOIN::init(THD*, List<Item>&, unsigned long 
long, select_result*) (sql_select.h:472)

==27244==    by 0x68408D: JOIN::JOIN(THD*, List<Item>&, unsigned long 
long, select_result*) (sql_select.h:421)

==27244==    by 0x77403D: mysql_select(THD*, Item***, TABLE_LIST*, 
unsigned int, List<Item>&, Item*, unsigned int, st_order*, st_order*, 
Item*, st_order*, unsigned long long, select_result*, 
st_select_lex_unit*, st_select_lex*) (sql_select.cc:2364)

==27244==    by 0x77982C: handle_select(THD*, st_lex*, select_result*, 
unsigned long) (sql_select.cc:271)

==27244==    by 0x6E28B7: execute_sqlcom_select(THD*, TABLE_LIST*) 
(sql_parse.cc:5018)

==27244==    by 0x6E47C7: mysql_execute_command(THD*) (sql_parse.cc:2210)

==27244==    by 0x8B4226: sp_instr_stmt::exec_core(THD*, unsigned int*) 
(sp_head.cc:2912)

==27244==    by 0x8B445E: sp_lex_keeper::reset_lex_and_exec_core(THD*, 
unsigned int*, bool, sp_instr*) (sp_head.cc:2740)

==27244==    by 0x8BA9D3: sp_instr_stmt::execute(THD*, unsigned int*) 
(sp_head.cc:2854)

==27244==    by 0x8B68A1: sp_head::execute(THD*) (sp_head.cc:1256)

==27244==    by 0x8B7670: sp_head::execute_procedure(THD*, List<Item>*) 
(sp_head.cc:1986)

==27244==    by 0x6EB374: mysql_execute_command(THD*) (sql_parse.cc:4359)

==27244==    by 0x6ED520: mysql_parse(THD*, char const*, unsigned int, 
char const**) (sql_parse.cc:5938)

==27244==    by 0x6EE2D7: dispatch_command(enum_server_command, THD*, 
char*, unsigned int) (sql_parse.cc:1216)

==27244==    by 0x6EF6B5: do_command(THD*) (sql_parse.cc:857)

==27244==

^ Found warnings in 
/home/msvensson/mysql/7.0/mysql-test/var/log/mysqld.1.1.err!!

How to repeat:
"./mtr --valgrind" on a mysqld  with a memory leak

Suggested fix:
mysql-test/include/check-warnings.test
=======================================

=== modified file 'mysql-test/include/check-warnings.test'

--- mysql-test/include/check-warnings.test	2009-03-02 12:48:35 +0000

+++ mysql-test/include/check-warnings.test	2009-09-23 17:30:05 +0000

@@ -57,6 +57,6 @@

if (`select @result = 0`){
skip OK;
}
--enable_query_log
-echo ^ Found warnings!!;
+echo ^ Found warnings in $log_error!!;
exit;

mysql-test/include/mtr_warnings.sql
=======================================

=== modified file 'mysql-test/include/mtr_warnings.sql'

--- mysql-test/include/mtr_warnings.sql	2009-07-10 11:35:53 +0000

+++ mysql-test/include/mtr_warnings.sql	2009-09-23 17:30:17 +0000

@@ -207,8 +207,8 @@

BEGIN
WHERE suspicious=1;
IF @num_warnings > 0 THEN
- SELECT file_name, line
+ SELECT line
FROM error_log WHERE suspicious=1;
--SELECT * FROM test_suppressions;
-- Return 2 -> check failed

mysql-test/mysql-test-run.pl
=======================================

=== modified file 'mysql-test/mysql-test-run.pl'

--- mysql-test/mysql-test-run.pl	2009-08-27 18:15:35 +0000

+++ mysql-test/mysql-test-run.pl	2009-09-23 17:41:23 +0000

@@ -1315,7 +1315,10 @@

sub command_line_setup {
push(@valgrind_args, @default_valgrind_args)
unless @valgrind_args;
+ # Make valgrind run in quiet mode so it only print errors
+ push(@valgrind_args, "--quiet" );
+
mtr_report("Running valgrind with options \"",
join(" ", @valgrind_args), "\"");
}

@@ -3654,8 +3657,8 @@

sub extract_warning_lines ($) {
# qr/^Error:|\[ERROR\]/,
qr/^Warning:|mysqld: Warning/,
qr/^Error:/,
- qr/^==.* at 0x/,
+ qr/^==\d*==/, # valgrind errors
qr/InnoDB: Warning|InnoDB: Error/,
qr/^safe_mutex:|allocated at line/,
qr/missing DBUG_RETURN/,
[24 Sep 2009 14:10] 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/84509
[25 Sep 2009 9:27] Bjørn Munch
Need to confirm that PB2 doesn't get affected by the outpout change (very unlikely I think).

I would drop the !! after the file name, thus:

echo ^ Found warnings in $log_error;

Whed adding --quiet to valgrind, what do you actually loose? I'm not very familiar with use of valgrind.
[29 Sep 2009 13:08] Magnus Blåudd
Review comments: The !! should be removed.
[30 Sep 2009 8:13] Bugs System
Pushed into 5.1.37-ndb-6.2.19 (revid:frazer@mysql.com-20090929142503-sst6g3fs0vx9fgil) (version source revid:magnus.blaudd@sun.com-20090924173739-62dwkcul4q6s1oa8) (merge vers: 5.1.37-ndb-6.2.19) (pib:11)
[30 Sep 2009 8:13] Bugs System
Pushed into 5.1.37-ndb-6.3.28 (revid:jonas@mysql.com-20090930070741-13u316s7s2l7e1ej) (version source revid:magnus.blaudd@sun.com-20090924173950-ma05nambynm62m2x) (merge vers: 5.1.37-ndb-6.3.27) (pib:11)
[30 Sep 2009 8:14] Bugs System
Pushed into 5.1.37-ndb-7.0.9 (revid:jonas@mysql.com-20090930075942-1q6asjcp0gaeynmj) (version source revid:magnus.blaudd@sun.com-20090924174115-z012rj4y33jer1sf) (merge vers: 5.1.37-ndb-7.0.8) (pib:11)
[30 Sep 2009 8:15] Bugs System
Pushed into 5.1.35-ndb-7.1.0 (revid:jonas@mysql.com-20090930080049-1c8a8cio9qgvhq35) (version source revid:magnus.blaudd@sun.com-20090924180306-fqpvi5rn1mqjvmid) (merge vers: 5.1.35-ndb-7.1.0) (pib:11)
[7 Oct 2009 14:26] 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/86028
[8 Oct 2009 8:45] Magnus Blåudd
Pushed to 5.1-mtr
[22 Oct 2009 20:17] Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091022201524-0efl2fzebfuuf0vk) (version source revid:bjorn.munch@sun.com-20091008122436-bqmy3lmr9iaw4d4s) (merge vers: 6.0.14-alpha) (pib:13)
[22 Oct 2009 20:18] Bugs System
Pushed into 5.5.0-beta (revid:alik@sun.com-20091022201318-jfvtrzd6lb07cwp5) (version source revid:bjorn.munch@sun.com-20091008093442-or0trmzmb2pqcyk7) (merge vers: 5.4.5-beta) (pib:13)
[22 Oct 2009 23:23] Paul DuBois
Test suite change. No changelog entry needed.

Setting report to NDI pending push into 5.1.x.
[23 Oct 2009 7:33] Bugs System
Pushed into 5.1.41 (revid:bjorn.munch@sun.com-20091021073307-ummbh6668hvfxqjv) (version source revid:bjorn.munch@sun.com-20091021073307-ummbh6668hvfxqjv) (merge vers: 5.1.41) (pib:13)
[23 Oct 2009 15:19] Paul DuBois
Test suite change. No changelog entry needed.
[18 Dec 2009 10:37] 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:53] 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:08] 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:22] 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)