1014125 - (--bisect-chunk) add the ability to investigate a failing test

Status: RESOLVED FIXED

(Testing :: Mochitest, defect)

Description

[Vaibhav (:vaibhav1994)]

As part of the GSoC project(Mochitest Failure Investigator), addition of 
--bisect-chunk option is required. This option will find take a testname as input
and work backwards to find its failure point.

Abstract: https://www.google-melange.com/gsoc/project/details/google/gsoc2014/vaibhavag/5741031244955648

Comment 1

[Joel Maher ( :jmaher ) (UTC -8)]

lets file bugs as needed to fill in missing pieces.  There will be a series of patches here as we make this a reality.

Comment 2

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk.patch

Initial Patch

Comment 3

[Vaibhav (:vaibhav1994)]

Attachment: advanced1.patch

Another Patch in continuation.

Comment 4

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk.patch

Comment 5

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk.patch

Re-factored Patch

Comment 6

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk_try.patch

Comment 7

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk_try.patch

Comment 8

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk.patch

Re-factored patch with putting the main logic into bisection.py

Comment 9

[Vaibhav (:vaibhav1994)]

Attachment: sanity_check.patch

Comment 10

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk(2.0)

Comment 11

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8440087 [details] [diff] [review]
bisect_chunk(2.0)

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

some general cleanup, overall this is shaping up well.  We are using Binary search vs Reverse search, can our initial patch just have the single algorithm, and a followup patch could have another algorithm?  this would make bisection.py much smaller and easier to digest.

::: testing/mochitest/bisection.py
@@ +22,5 @@
> +        """
> +            Make a list of tests for bisection by parsing manifests
> +        """
> +        bisectlist = []
> +        

nit: when you have a blank line, please remove any spaces/tabs- there are 6 in this file

@@ +157,5 @@
> +                status = -1
> +            
> +        return status
> +
> +    def sanityCheck(self, options, contents, summary):

s/sanityCheck/verifyNoErrors/

::: testing/mochitest/runtests.py
@@ +451,3 @@
>      """ Build the url path to the specific test harness and test file or directory
>          Build a manifest of tests to run and write out a json file for the harness to read
>      """

can you please describe what testsToFilter is for?

@@ +1346,5 @@
> +    if options.bisectChunk == "default":
> +      if options.runByDir:
> +        self.doMochitests(options, onLaunch)
> +      else:
> +        self.doTests(options, onLaunch)

why can't we call doMochitests here?

@@ +1352,5 @@
> +        options.bisectChunk = key
> +        break
> +      # if options.bisectChunk is still default that means that all the tests have passed.
> +      if options.bisectChunk == "default":
> +        return 0

actually:
if len(self.expectedErrors) == 0:
  return 0
options.bisectChunk = self.exectedError[self.expectedError.keys()[0]]

@@ +1455,5 @@
> +      # code for --bisect-chunk(bisection of tests). Under Testing.
> +      if options.bisectChunk:
> +        status = self.doBisection(options, onLaunch)
> +        if status == -1:
> +          return status

do you use status for anything else, I would recommend:
if self.doBisection(options, onLaunch) == -1:
  return -1

@@ +1876,5 @@
>      dirlist.sort()
>      return dirlist
>  
> +  def initializeLooping(self, options):
> +    #initialize variables

this comment isn't very descriptive

Comment 12

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk(2.0)

Fixed the nits in the previous patch. :ted and :ahal, I would like to get your feedback for this patch.

Comment 13

[Andrew Halberstadt [:ahal]]

Comment on attachment 8440262 [details] [diff] [review]
bisect_chunk(2.0)

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

I mainly looked at the changes to runtests.py, as I'm very interested in making sure that doesn't get even more confusing than it already is :). Overall I think the changes look good. But I am worried that this is making mochitests even more confusing, so I have some suggestions to help fix it.

General nit: Please use underscores instead of camelCase in variable and method names, especially in the new bisect module (see http://python.org/dev/peps/pep-0008/#naming-conventions). As runtests.py mostly uses camelCase (though not everywhere!) I guess it is ok to leave that as is.

General nit: Mochitest is already extremely difficult to read and follow along, and this patch seems to add even more cryptic methods and code paths. I'd like to see more useful method and variable names, along with docstrings and comments explaining what they do. For example, what's the difference between buildTestPath and getTestsToRun? What is doMochitests? How does it differ from doTests? What is looping? When and why does it need to be initialized?

::: testing/mochitest/runtests.py
@@ +1351,5 @@
> +      testsToRun.append(tp)
> +
> +    return testsToRun
> +
> +  def doMochitests(self, options, onLaunch=None, testsToRun=None):

I'm not a fan of this method name, I have no idea what it's purpose is.

@@ +1353,5 @@
> +    return testsToRun
> +
> +  def doMochitests(self, options, onLaunch=None, testsToRun=None):
> +    # We have kept the call to doTests in this method and not in bisection.py because
> +    # we need to prevent cyclic importing.

What do you mean cyclic importing? That shouldn't be a problem in python.

@@ +1729,5 @@
> +        self.harness.result[key] = "FAIL"
> +      elif "TEST-KNOWN-FAIL" in line:
> +        key = line.split('|')[-2].split('/')[-1].strip()
> +        self.harness.result[key] = "TODO"
> +      return line

Why are we parsing the log again again here? You may want to take a look at the patch in bug 886570. If this isn't a huge rush, I'd say rebase your patch on top of that. Otherwise, this is going to get removed again as soon as the other bug lands.

@@ +1736,5 @@
> +      if "TEST-UNEXPECTED-FAIL" in line:
> +        key = line.split('|')[-2].split('/')[-1].strip()
> +        if key not in self.harness.expectedError:
> +          self.harness.expectedError[key] = line.split('|')[-1].strip()
> +      return line

Same comment as above.

Comment 14

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk.patch

Added comments to functions and used underscores to name them instead of camelCase (thanks :ahal!). Also, removed doMochitests function and instead added a check inside doTests. I haven't yet dealt with log parsing stuff because bug 886570 has not yet landed. I can deal with that once that patch lands.

Comment 15

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8443009 [details] [diff] [review]
bisect_chunk.patch

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

this patch has come a long way in the right direction.

Ideally the doBisection would be in bisection.py.  If there are circular dependencies, could we make bisect a subclass of mochitest?  Maybe that will get us thinking of other ways to make it work.

Speaking of doBisection, I would like to see something more like this:
def doBisection():
  bisect.initialize(options)
  tests = bisect.getTestsToRun(options)
  while stillBisecting:
    # if options.bisectChunk == 'default' we train the run, otherwise we start on the first iteration
    testsToRun = bisect.get_test_chunk(options, tests)
    mochitest.doTests(testsToRun)
    # increment state, print out status
    status = bisect.summarize_chunk()
    if status == done:
       # remove the test case that is failing from the list, we will loop once more for a sanity check
       # set options.bisectChunk = 'default', etc.
       bisect.remove_target()
    elif status == nofailure:
       print summary
       break

that is just a general flow, I think we can get this into bisection.py and make it a bit cleaner- the devil is in the details.

Great work so far, this is cleaning up nicely.

::: testing/mochitest/bisection.py
@@ +1,3 @@
> +import mozinfo
> +import mozprocess
> +import mozrunner

do we need mozinfo, mozprocess and mozrunner?

@@ +4,5 @@
> +import os
> +import math
> +
> +class Bisect(object):
> +    "Class for creating, bisecting and summarizing for --bisect-chunk option."

is this a valid comment in python?

@@ +67,5 @@
> +
> +        return contents
> +
> +    def run_bisect_chunk(self, options, contents, summary, onLaunch=None):
> +        "This method is used summarize the results after the list of tests is run."

we should call this summarize_chunk()

::: testing/mochitest/runtests.py
@@ +451,3 @@
>      """ Build the url path to the specific test harness and test file or directory
>          Build a manifest of tests to run and write out a json file for the harness to read
> +        TestsToFilter option is used to filter/keep the tests provided in the list

lower case this to testsToFilter

@@ +1339,5 @@
> +    options.manifestFile = None
> +    options.profilePath = tempfile.mkdtemp()
> +    self.urlOpts = []
> +
> +  def getTestsToRun(self, options):

can we convert the other calls to the manifests to use this as well?  I believe it is only in buildTestPath.

@@ +1352,5 @@
> +    tests = manifest.active_tests(disabled=False, options=options, **info)
> +
> +    # Sorting the list of tests according to path to filter the tests which
> +    # occur before the failing test.
> +    tests = sorted(tests, key=lambda k: k['path'])

does this sort the full path including the directories?  This could adjust the order of tests to run.  I see this sort method currently being used:
http://mxr.mozilla.org/mozilla-central/source/testing/mochitest/runtests.py#516

@@ +1360,5 @@
> +      pathAbs = os.path.abspath(test['path'])
> +      assert pathAbs.startswith(self.testRootAbs)
> +      tp = pathAbs[len(self.testRootAbs):].replace('\\', '/').strip('/')
> +
> +      testsToRun.append(tp)

there is a blank line above this, can we remove that?

@@ +1383,5 @@
> +    summary = []
> +    bisectInProgress = True
> +    contents = {}
> +    contents['tests'] = tests
> +    contents['loop'] = 0

can this chunk of code live in bisect.setup() or bisect.initialize() ?

@@ +1394,5 @@
> +        contents = bisect.next_chunk_reverse(options, contents, status)
> +
> +        self.doTests(options, onLaunch, contents['testsToRun'])
> +        bisect.reset(self.expectedError, self.result)
> +        status = bisect.run_bisect_chunk(options, contents, summary, onLaunch)

this will look nicer as:
status = bisect.summarize_chunk(options, contents, summary, onLaunch)

@@ +1416,5 @@
> +      self.doTests(options, onLaunch, contents['testsToRun'])
> +      bisect.reset(self.expectedError, self.result)
> +      status = bisect.verify_no_errors(options, contents, summary)
> +      if status == -1:
> +        bisectInProgress = False

we are inside a while loop 'while bisectInProgress', is there a way we could make bisect.next_chunk_reverse() understand that this is a sanity run or a training run? which would remove many of the duplicated lines of code.

@@ +1436,5 @@
>      self.testRoot = self.getTestRoot(options)
>      self.testRootAbs = os.path.join(SCRIPT_DIR, self.testRoot)
>  
> +    self.expectedError = {}
> +    self.result = {}

can these reset values be done in initializeLoop or some cleanup function?

@@ +1438,5 @@
>  
> +    self.expectedError = {}
> +    self.result = {}
> +    # hack for try.
> +    options.bisectChunk = "default"

this hack shouldn't be in a patch we are reviewing.

@@ +1470,5 @@
>  
> +      # code for --bisect-chunk(bisection of tests). Under Testing.
> +      if options.bisectChunk:
> +        if self.doBisection(options, onLaunch) == -1:
> +          return -1

if we are running in runByDir (i.e. a loop of >1 dir), do we really want to return -1 here, or 'continue' to the next directory?

Comment 16

[Vaibhav (:vaibhav1994)]

Attachment: refactored-bisect-chunk.patch

> +    options.manifestFile = None
> +    options.profilePath = tempfile.mkdtemp()
> +    self.urlOpts = []
> +
> +  def getTestsToRun(self, options):

I have filed Bug 1028226 which I would deal once this patch is landed. 
Also, I haven't yet dealt with log parsing stuff because bug 886570 has not yet landed.

Also, with this patch the majority of the code is shifted to bisection.py and minimal code is in runtests.py

Comment 17

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8444118 [details] [diff] [review]
refactored-bisect-chunk.patch

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

as discussed in IRC- we have come a long way to clean this up, but there are some better steps we can take to make doBisection work without circular dependencies or subclassing.

::: testing/mochitest/bisection.py
@@ +60,5 @@
> +                sanityCheckDone = True
> +            elif status == -1:
> +                bisectInProgress = False
> +            else:
> +                sanityCheckDone = False

reading this code, I had some confusion around the sanityCheckDone bits.  This appears to be needed as we might have >1 failure- either a comment or some type of refactor.

::: testing/mochitest/runtests.py
@@ +494,5 @@
>            continue
>  
> +        if testsToFilter:
> +          if tp not in testsToFilter:
> +            continue

if testsToFilter and (tp not in testsToFilter):
  continue

@@ +1406,5 @@
> +      if options.bisectChunk:
> +        runStatus = bisect.doBisection(options, onLaunch)
> +        if runStatus == -1:
> +          return -1
> +

nit: we don't need an extra line here.

@@ +1608,5 @@
>                self.trackShutdownLeaks,
>                self.log,
>                self.countline,
> +              self.first_error,
> +              self.record_result,

if we could add a variable to outputhandler to account for bisection, then we could optionally add these, this way they are not added for all output handlers.

Comment 18

[Andrew Halberstadt [:ahal]]

Comment on attachment 8444118 [details] [diff] [review]
refactored-bisect-chunk.patch

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

Awesome, this looks a lot better! I'll leave the review to Joel as he understands this project better than me. I'll stick to general feedback :)

General nit: still a fair bit of camelCase in bisection.py, but looking better!

::: testing/mochitest/bisection.py
@@ +159,5 @@
> +                status = -1
> +
> +        return status
> +
> +    def summarization(self, summary, string, a=None, b=None, c=None, d=None):

This method doesn't scale and isn't making anything easier. Instead, use kwarg substitution:

values = { 'passed': 4, 'failed': 1, 'foo': 'bar' }
string = "This is the summary: %(passed)s, %(failed)s"
summary.append(string % values)

Notice how extra keys in 'values' are ignored. This means you can build the dictionary once and then use it for every substitution, no matter how many %s's there are in any given string.

::: testing/mochitest/mach_commands.py
@@ +535,5 @@
>      func = runbydir(func)
>  
> +    bisect_chunk = CommandArgument('--bisect-chunk', type=str,
> +                                 dest='bisectChunk',
> +        help='Specify the failing test name to find the failure point.')

Reading this help message, I still don't really understand what this is doing. If we know the failing test name, then what is this failure point that we are finding?

::: testing/mochitest/runtests.py
@@ +446,5 @@
>      elif options.browserChrome:
>        testURL = "about:blank"
>      return testURL
>  
> +  def buildTestPath(self, options, testsToFilter = None):

nit: don't put spaces around the '=' in a function call

Comment 19

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk.patch

I have tried to make the patch cleaner. Also, I have not fully dealt with cleaning up the manifest parsing part, I will do that completely in Bug 1028226

Comment 20

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8447300 [details] [diff] [review]
bisect_chunk.patch

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

yay, this is a lot cleaner, a few nits.

Next steps:
* push to try, ensure b2g, android, debug, opt work as expected (i.e. with no hacks)
* verify this finds an error on try server for a single platform
* get review with updated patch (with nits addressed) from ahal (ted is on vacation next week) or wlach.
** the reason for this is a second set of eyes as I have been deep in this code for a long time

Well done!

::: testing/mochitest/bisection.py
@@ +37,5 @@
> +                break
> +
> +        return bisectlist
> +
> +    def preTest(self, options, tests, status):

pre_test

@@ +47,5 @@
> +            status = self.setup(tests)
> +
> +        return self.next_chunk_reverse(options, status)
> +
> +    def postTest(self, options, expectedError, result):

post_test

::: testing/mochitest/runtests.py
@@ +1416,5 @@
> +    # We need to print the summary only if options.bisectChunk has a value.
> +    # Also we need to make sure that we do not print the summary in between running tests via --run-by-dir.
> +    if options.bisectChunk and options.bisectChunk in self.result:
> +      bisect.print_summary()
> +      return -1

why return -1, we don't return anything otherwise, we should explicitly return a code in all paths or not at all

@@ +1539,5 @@
>  
> +      if options.bisectChunk:
> +        bisectChunk = True
> +      else:
> +        bisectChunk = False

why do you do this?  It is either None or a string, we could be fine without this I would think.

Comment 21

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk.patch

Fixed the nits pointed out by :jmaher (thanks!) and added additional methods based on the failures on try.

https://tbpl.mozilla.org/?tree=Try&rev=07bbcb4a3e98 -- the patch is successfully running on for all platforms.

https://tbpl.mozilla.org/?tree=Try&rev=e0441254257d -- this push bisects the error for a unit test made to fail purposely. Look at the logs here: https://tbpl.mozilla.org/php/getParsedLog.php?id=42815619&tree=Try&full=1 and search for "Bisection Summary" to get an overview of the bisection. The "green" colour ("orange" would have been better in this case) that is being shown in the try push for the 5th chunk is misleading, which is probably because the last sanity check passed without errors and the tbpl is giving its outcome based on only that part.

:wlach I would like to get your views on this patch. Thanks!

Comment 22

[William Lachance (:wlach)]

Comment on attachment 8448518 [details] [diff] [review]
bisect_chunk.patch

Hey, I'm on holiday until Friday and don't have time to give this the close attention it deserves. Reassigning to ahal, who should hopefully have time to take a look.

Comment 23

[Andrew Halberstadt [:ahal]]

Comment on attachment 8448518 [details] [diff] [review]
bisect_chunk.patch

Jmaher's already given r+ and I've previously looked at this and given f+.. so feel free to land this Vaibhav, unless you really want to wait for Will to come back :) (if so I'd flag him for feedback, not review).

Comment 24

[Andrew Halberstadt [:ahal]]

Comment on attachment 8448518 [details] [diff] [review]
bisect_chunk.patch

Oh sorry, I missed Joel's comment asking you to get review from one of us.

Comment 25

[Vaibhav (:vaibhav1994)]

Attachment: shutdown.patch

A small patch to support shutdown/leak. In testing phase.

Comment 26

[Vaibhav (:vaibhav1994)]

Attachment: testing.patch

Work In Progress

Comment 27

[Andrew Halberstadt [:ahal]]

Comment on attachment 8448518 [details] [diff] [review]
bisect_chunk.patch

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

Lgtm, r+ with comments addressed.

::: testing/mochitest/bisection.py
@@ +46,5 @@
> +                    test_dirs.append(directory)
> +                else:
> +                    tests_by_dir[directory].append(test)
> +
> +            tests_per_chunk = (len(test_dirs) * 1.0) / options.totalChunks

nit: just use float(len(test_dirs))

@@ +156,5 @@
> +            # if no expectedError that means all the tests have successfully passed.
> +            if len(self.expectedError) == 0:
> +                return -1
> +            options.bisectChunk = self.expectedError.keys()[0]
> +            self.summarization("\tFound Error in test: %s", options.bisectChunk)

Just call self.summary.append() directly, that summarization method isn't making anything easier.

::: testing/mochitest/mochitest_options.py
@@ +154,5 @@
> +        [["--bisect-chunk"],
> +        { "action": "store",
> +          "type": "string",
> +          "dest": "bisectChunk",
> +          "help": "Specify the failing test name to find the failure point.",

Change this to match the help in mach_commands.py

::: testing/mochitest/runtests.py
@@ +1389,5 @@
> +      testsToRun.append(test['path'])
> +
> +    return testsToRun
> +
> +  def runMochitests(self, options, onLaunch=None):

I don't like inserting yet another method into the mochitest startup sequence.. would it be difficult to merge this into doTests? If not it would be difficult, it isn't a big deal.

@@ +1730,5 @@
> +      if "TEST-UNEXPECTED-FAIL" in line:
> +        key = line.split('|')[-2].split('/')[-1].strip()
> +        if key not in self.harness.expectedError:
> +          self.harness.expectedError[key] = line.split('|')[-1].strip()
> +      return line

Sigh, this is going to conflict with the mochitest structured logging patch again.. not you're fault though. I guess whoever lands last gets to deal with bitrot.

Comment 28

[Vaibhav (:vaibhav1994)]

Attachment: bisect_chunk.patch

Fixed most of the nits pointed by :ahal.
Regarding inserting "def runMochitests" inside "def doTests", as discussed in IRC, I want to keep the method separate because I do not want to mix bisection with doTests which is used for building the profile.

Carrying forward the r+ of :ahal.

Comment 29

[Carsten Book [:Tomcat]]

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

Comment 30

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

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