1068429 - check_for_crashes should be replaced with log_crashes wherever structured logging is in use

Status: RESOLVED FIXED

(Testing :: Mozbase, defect)

Description

[Chris Manchester (limited bugmail, email directly)]

This will be an unstructured side channel for failure output until it is, so is required for the mozharness refactor. Looks like a drop in replacement, but we'll have to detect whether structured logging is available for the mozrunner case.

What's the way to manufacture a crash to test this out?

Comment 1

[James Graham [:jgraham]]

I force crashes by using a null pointer deref in chrome js:

Cu.import("resource://gre/modules/ctypes.jsm");
let zero = new ctypes.intptr_t(8);
let badptr = ctypes.cast(zero, ctypes.PointerType(ctypes.int32_t));
badptr.contents;

(this is the kind of thing that we could put into a testing metaharness).

Comment 2

[(not currently active) Ted Mielczarek]

There's also CrashTestUtils.jsm, but that's mostly if you need specific kinds of crashes:
http://mxr.mozilla.org/mozilla-central/source/toolkit/crashreporter/test/CrashTestUtils.jsm?force=1

jgraham's method will work fine.

Comment 3

[Chris Manchester (limited bugmail, email directly)]

Not a drop in replacement, because check_for_crashes has a return value used by the harnesses. log_crashes seems clearly intended to have a side effect so probably should be renamed, or mozcrash should expose this elsewhere.

Comment 4

[Chris Manchester (limited bugmail, email directly)]

Attachment: Provide an indication whether a crash was logged by log_crashes

I imagine someone has an opinion about this.

Comment 5

[James Graham [:jgraham]]

Comment on attachment 8492234 [details] [diff] [review]
Provide an indication whether a crash was logged by log_crashes

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

I don't know what the use case is here, but using a stateful API seems rather wonky. If we need to know whether the current log_crashes() actually logged anything it could return a boolean:

diff --git a/testing/mozbase/mozcrash/mozcrash/mozcrash.py b/testing/mozbase/mozcrash/mozcrash/mozcrash.py
index c41c16c..204ab17 100644
--- a/testing/mozbase/mozcrash/mozcrash/mozcrash.py
+++ b/testing/mozbase/mozcrash/mozcrash/mozcrash.py
@@ -116,11 +116,14 @@ def log_crashes(logger,
                 stackwalk_binary=None,
                 dump_save_path=None):
     """Log crashes using a structured logger"""
+    logged_crash = False
     for info in CrashInfo(dump_directory, symbols_path, dump_save_path=dump_save_path,
                           stackwalk_binary=stackwalk_binary):
         kwargs = info._asdict()
         kwargs.pop("extra")
         logger.crash(process=process, test=test, **kwargs)
+        logged_crash = True
+    return logged_crash

Comment 6

[Chris Manchester (limited bugmail, email directly)]

(In reply to James Graham [:jgraham] from comment #5)
> Comment on attachment 8492234 [details] [diff] [review]
> Provide an indication whether a crash was logged by log_crashes
> 
> Review of attachment 8492234 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> I don't know what the use case is here, but using a stateful API seems
> rather wonky. If we need to know whether the current log_crashes() actually
> logged anything it could return a boolean:
> 
> diff --git a/testing/mozbase/mozcrash/mozcrash/mozcrash.py
> b/testing/mozbase/mozcrash/mozcrash/mozcrash.py
> index c41c16c..204ab17 100644
> --- a/testing/mozbase/mozcrash/mozcrash/mozcrash.py
> +++ b/testing/mozbase/mozcrash/mozcrash/mozcrash.py
> @@ -116,11 +116,14 @@ def log_crashes(logger,
>                  stackwalk_binary=None,
>                  dump_save_path=None):
>      """Log crashes using a structured logger"""
> +    logged_crash = False
>      for info in CrashInfo(dump_directory, symbols_path,
> dump_save_path=dump_save_path,
>                            stackwalk_binary=stackwalk_binary):
>          kwargs = info._asdict()
>          kwargs.pop("extra")
>          logger.crash(process=process, test=test, **kwargs)
> +        logged_crash = True
> +    return logged_crash

The use case is setting the harness return code (or just return value from runTests) based on a crash. I'm not that invested in the exact approach taken, but in defense of this approach the api already seems pretty stateful because processing a dump has the side effect of removing the original dump files (and optionally saving them). Returning a value from a method called "log_crashes" is a little wonky, too.

Comment 7

[(not currently active) Ted Mielczarek]

Comment on attachment 8492234 [details] [diff] [review]
Provide an indication whether a crash was logged by log_crashes

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

That's gross. Why not just make log_crashes return a count of crashes it logged?

Comment 8

[Chris Manchester (limited bugmail, email directly)]

Attachment: Provide an indication whether a crash was logged by log_crashes

Comment 9

[Chris Manchester (limited bugmail, email directly)]

Attachment: Trivial fixes for formatting crashes in the tbplformatter.

A bug fix and simple modification for compatibility with existing output.

Try:
https://tbpl.mozilla.org/?tree=Try&rev=f9c11ae4b5ab

Comment 10

[Chris Manchester (limited bugmail, email directly)]

Attachment: Log crashes with structured logging for those using structured logging.

Logging some crashes:
https://tbpl.mozilla.org/?tree=Try&rev=6b8a149a7b80

Comment 11

[Andrew Halberstadt [:ahal]]

Comment on attachment 8493315 [details] [diff] [review]
Log crashes with structured logging for those using structured logging.

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

Looks good, a couple comments that apply to all modified files.

::: build/mobile/b2gautomation.py
@@ +117,5 @@
>              try:
> +                logger = get_default_logger()
> +                if logger is not None:
> +                    crash_count = mozcrash.log_crashes(logger, local_dump_dir, symbolsPath,
> +                                                       test=self.lastTestSeen)

Can we save the arguments in a mozcrash_args variable so they only need to be updated in one place?

@@ +118,5 @@
> +                logger = get_default_logger()
> +                if logger is not None:
> +                    crash_count = mozcrash.log_crashes(logger, local_dump_dir, symbolsPath,
> +                                                       test=self.lastTestSeen)
> +                    crashed = crash_count > 0

It's probably ok to just set crashed to the return value of log_crashes.

Comment 12

[Chris Manchester (limited bugmail, email directly)]

(In reply to Andrew Halberstadt [:ahal] from comment #11)
> Comment on attachment 8493315 [details] [diff] [review]
> Log crashes with structured logging for those using structured logging.
> 
> Review of attachment 8493315 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Looks good, a couple comments that apply to all modified files.
> 
> ::: build/mobile/b2gautomation.py
> @@ +117,5 @@
> >              try:
> > +                logger = get_default_logger()
> > +                if logger is not None:
> > +                    crash_count = mozcrash.log_crashes(logger, local_dump_dir, symbolsPath,
> > +                                                       test=self.lastTestSeen)
> 
> Can we save the arguments in a mozcrash_args variable so they only need to
> be updated in one place?

Maybe I don't see what you mean, but the argument names aren't identical, so I don't think so.

> 
> @@ +118,5 @@
> > +                logger = get_default_logger()
> > +                if logger is not None:
> > +                    crash_count = mozcrash.log_crashes(logger, local_dump_dir, symbolsPath,
> > +                                                       test=self.lastTestSeen)
> > +                    crashed = crash_count > 0
> 
> It's probably ok to just set crashed to the return value of log_crashes.

Comment 13

[(not currently active) Ted Mielczarek]

Comment on attachment 8493273 [details] [diff] [review]
Provide an indication whether a crash was logged by log_crashes

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

Looks good, thanks!

Comment 14

[Chris Manchester (limited bugmail, email directly)]

remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/37935ebab1d1
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/8b6aebc85b17
remote:   https://hg.mozilla.org/integration/mozilla-inbound/rev/1244ab6f3d0e

Comment 15

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/37935ebab1d1
https://hg.mozilla.org/mozilla-central/rev/8b6aebc85b17
https://hg.mozilla.org/mozilla-central/rev/1244ab6f3d0e