966864 - |mach valgrind-test|: Parse Valgrind output so that different errors are distinguished for TBPL

Status: RESOLVED FIXED

(Testing :: General, defect)

Description

[Nicholas Nethercote [inactive]]

Current if |mach valgrind-test| detects any errors it just prints this:

  TEST-UNEXPECTED-FAIL | valgrind-test | valgrind found errors

This is hopeless for starring failures on TBPL, because there is no distinction between different errors.

Comment 1

[Nicholas Nethercote [inactive]]

Attachment: |mach valgrind-test|: Parse Valgrind output so that different errors are distinguished for TBPL.

This patch implements more detailed parsing of Valgrind's output, in order to
extract better failure messages. Here's an example showing the TEST-UNEXPECTED-FAIL that is now shown *before* the corresponding Valgrind error:

> TEST-UNEXPECTED-FAIL | valgrind-test | 4 bytes in 1 blocks are definitely lost at malloc / XPCJSRuntime::XPCJSRuntime / XPCJSRuntime::newXPCJSRuntime / nsXPConnect::nsXPConnect
> 
> ==23260== 4 bytes in 1 blocks are definitely lost in loss record 85 of 9,277
> ==23260==    at 0x4C2A2DB: malloc (in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so)
> ==23260==    by 0x89E0DA1: XPCJSRuntime::XPCJSRuntime(nsXPConnect*) (XPCJSRuntime.cpp:3151)
> ==23260==    by 0x89E0E1C: XPCJSRuntime::newXPCJSRuntime(nsXPConnect*) (XPCJSRuntime.cpp:3165)
> ==23260==    by 0x89F85DC: nsXPConnect::nsXPConnect() (nsXPConnect.cpp:84)
> ==23260==    by 0x89F8619: nsXPConnect::InitStatics() (nsXPConnect.cpp:130)
> ==23260==    by 0x89E0EF6: xpcModuleCtor() (XPCModule.cpp:13)
> ==23260==    by 0x89ACDF2: Initialize() (nsLayoutModule.cpp:404)
> ==23260==    by 0x7D6A14E: nsComponentManagerImpl::KnownModule::Load() (nsComponentManager.cpp:724)
> ==23260==    ...

You can see it's a shortened form -- not enough to understand what the error
is, but enough that different errors will show up as clearly different in the
TBPL logs.

Parsing Valgrind's output is potentially fragile, so I've implemented a sanity
check in the code that should cause the test to fail if any errors fail to be
parsed. See the comments in the patch for details.

Comment 2

[Gary Kwong [:gkw] [:nth10sd] (NOT official MoCo now)]

Comment on attachment 8369296 [details] [diff] [review]
|mach valgrind-test|: Parse Valgrind output so that different errors are distinguished for TBPL.

Review of attachment 8369296 [details] [diff] [review]:
-----------------------------------------------------------------

::: build/valgrind/mach_commands.py
@@ +94,5 @@
> +            # Look for the start of a Valgrind error.
> +            error = self.is_error_line(line)
> +            if error:
> +                self.num_errors_seen += 1
> +                self.num_stack_entries_to_get = 4

There might be instances where we might need more than 4 lines but I guess those may be a rarity.

Comment 3

[Nicholas Nethercote [inactive]]

Attachment: Stop highlighting Valgrind's "ERROR SUMMARY" line, because it's no longer needed.

Comment 4

[Ed Morley [:emorley]]

Comment on attachment 8369763 [details] [diff] [review]
Stop highlighting Valgrind's "ERROR SUMMARY" line, because it's no longer needed.

I've just double checked that valgrind.sh uses mach and so the other patch will take effect on automation jobs, and it does (first job type in automation to use it I think.. we're yet to switch over most of the others) - so this looks good, thank you :-)

Comment 5

[Gregory Szorc [:gps]]

Comment on attachment 8369296 [details] [diff] [review]
|mach valgrind-test|: Parse Valgrind output so that different errors are distinguished for TBPL.

Review of attachment 8369296 [details] [diff] [review]:
-----------------------------------------------------------------

I didn't look too much at the parsing code. I figure Gary has that covered.

::: build/valgrind/mach_commands.py
@@ +26,5 @@
>  
>  
> +class OutputHandler(object):
> +    '''
> +    A class for handling Valgrind output.

This is the kind of class that really needs to belong in its own reusable .py module. Please read the "minimizing code in commands" section in python/mach/README.rst.

Unit tests for this module would also be great. I'd hate for us to stop detecting Valgrind errors because of a failure in the parser. It's happened before with other test suites.

@@ +69,5 @@
> +            r'^==\d+== (Mismatched free\(\) / delete / delete \[\])',
> +            r'^==\d+== (Invalid (read|write) of size \d+)',
> +            r'^==\d+== (Jump to the invalid address stated on the next line)',
> +            r'^==\d+== (Source and destination overlap in .*)',
> +            r'^==\d+== (.* bytes in .* blocks are .* lost)',

Can these messages be localized? Should we set LANG before invoking Valgrind to force English?

@@ +76,5 @@
> +        self.re_suppression = r' *<insert_a_suppression_name_here>'
> +        self.num_errors_seen = 0
> +        self.num_suppressions_seen = 0
> +        self.num_stack_entries_to_get = 0
> +        self.curr_failure_msg = None

Nit: Python style frowns upon abbreviations. num_ is arguably not necessary anyway.

@@ +83,5 @@
> +    def is_error_line(self, line):
> +        # Look for the start of a Valgrind error.
> +        ret = False
> +        for r in self.error_re_list:
> +            m = re.match(r, line)

Could you join error_re_list with "|" to allow for alternate patterns? A single monolithic pattern is typically faster than N comparisons.

Comment 6

[Nicholas Nethercote [inactive]]

> This is the kind of class that really needs to belong in its own reusable .py module.

And put it build/valgrind/, I guess?

> Unit tests for this module would also be great. I'd hate for us to stop
> detecting Valgrind errors because of a failure in the parser. It's happened
> before with other test suites.

I'm having trouble imagining how the unit test would work -- AFAICT require that you have Valgrind installed on your machine, and an an appropriate (--enable-valgrind --disable-jemalloc) Firefox build, and then apply a patch that deliberately introduces one or more errors into Firefox, and then check the output. That's how I've been manually testing it, but it seems hard to automate.

That's why I built in the consistency check (see the comment starting with "Parsing the Valgrind output isn't ideal..."). The parsing done for it is *much* simpler, and so much less likely to break... I wrote the Valgrind code that generates the suppressions over ten years ago and the particular line we look for hasn't changed in that time.

> Can these messages be localized? Should we set LANG before invoking Valgrind
> to force English?

Valgrind is English-only, has been for over ten years, and I don't see it changing :) I'll add a comment about this.

Comment 7

[Nicholas Nethercote [inactive]]

Attachment: |mach valgrind-test|: Parse Valgrind output so that different errors are distinguished for TBPL.

Changes:

- I moved OutputHandler into a module. I've never made a Python module before,
  but it seems to work.

- I merged the list of regexps into a single regexp.

- I changed the num_* identifers.

- I didn't add a unit test. As per comment 6, the built-in consistency
  checking is simpler, and I also think it's stronger -- it's always running,
  and so there's no concerns about coverage the way there is with a unit test.

  In fact, it just helped me discover a problem: I had '^' at the start of the
  regexp that looked for Valgrind's error messages, but it's possible that
  Firefox will produce console output without a newline, thus breaking that. So
  I removed the '^'. Unit testing would have been lucky to detect that, but the
  consistency check triggered the very first time it happened.

Comment 8

[Gregory Szorc [:gps]]

Comment on attachment 8371122 [details] [diff] [review]
|mach valgrind-test|: Parse Valgrind output so that different errors are distinguished for TBPL.

Review of attachment 8371122 [details] [diff] [review]:
-----------------------------------------------------------------

This is mostly a rubber stamp.

Comment 9

[Nicholas Nethercote [inactive]]

> This is mostly a rubber stamp.

Thanks! I mostly wanted a sanity-check of the module... and now I realize that I forgot to |hg add| build/valgrind/__init__.py, which is just an empty file. I will do so before landing.

Comment 10

[Nicholas Nethercote [inactive]]

> I realize that I forgot to |hg add| build/valgrind/__init__.py, which is
> just an empty file.

Actually I remembered, but Splinter doesn't show empty files.

Comment 11

[Nicholas Nethercote [inactive]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/ce819018434b

Comment 12

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/mozilla-central/rev/ce819018434b

Comment 13

[Nicholas Nethercote [inactive]]

And here's the TBPL patch:
https://hg.mozilla.org/webtools/tbpl/rev/dbe9ef485b38

I won't bother filing a bug about getting that patch into production; this isn't at all urgent, and so I'm happy for this to ride along whenever TBPL next gets updated.

Comment 14

[Ryan VanderMeulen [:RyanVM]]

(In reply to Nicholas Nethercote [:njn] from comment #13)
> And here's the TBPL patch:
> https://hg.mozilla.org/webtools/tbpl/rev/dbe9ef485b38

In production :)