1470151 - Reset gcov counters before every test and dump them before shutdown in per-test coverage mode (on Linux and for xpcshell)

Status: RESOLVED FIXED

(Testing :: Code Coverage, enhancement)

Description

[Marco Castelluccio [:marco]]

In order to have more precise coverage data in the per-test case, we should reset the counters before running a test, and dump them before shutting down.

Comment 1

[Marco Castelluccio [:marco]]

Attachment: WIP

This is a WIP patch that is adding support for xpcshell. There are still a few rough edges, or actually maybe just one: resetting/dumping the counters is currently an asynchronous operation, but we don't know when it ends (in the patch I've just added a timeout to wait a few seconds).

Comment 2

[Marco Castelluccio [:marco]]

Attachment: WIP

Comment 3

[Marco Castelluccio [:marco]]

Attachment: Part 1: Make dumpCoverage and resetCoverage return a Promise that is resolved when the parent process and all content processes are done with dumping or resetting coverage counters

This patch is making dumpCoverage and resetCoverage return a Promise which gets resolved when all processes are done, this way we don't have to insert arbitrary timeouts in the harness code.

I'm not really happy with the duplication of code between the "requestType == RequestType::Dump" and "requestType == RequestType::Reset" branches, but I was having a hard time sharing the code.

Doing something like:
> auto reject = [promise](ResponseRejectReason aReason) {
>   promise->MaybeReject(NS_ERROR_FAILURE);
> };
caused errors which were quite unreadable for my limited C++ experience.

Comment 4

[Nathan Froyd [:froydnj]]

Comment on attachment 8987127 [details] [diff] [review]
Part 1: Make dumpCoverage and resetCoverage return a Promise that is resolved when the parent process and all content processes are done with dumping or resetting coverage counters

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

I would be interested to see what the C++ errors looked like; the duplication of code there is really unfortunate.

f+, I guess, but this is not landable in its current state.

::: dom/ipc/ContentChild.cpp
@@ +3700,4 @@
>  {
>  #ifdef MOZ_CODE_COVERAGE
>    CodeCoverageHandler::DumpCounters(0);
> +  aResolver(true);

Feels like this should have some sort of /*unused*/ comment with it?

@@ +3712,4 @@
>  {
>  #ifdef MOZ_CODE_COVERAGE
>    CodeCoverageHandler::ResetCounters(0);
> +  aResolver(true);

Likewise here.

::: tools/code-coverage/nsCodeCoverage.cpp
@@ +49,5 @@
> +
> +  if (requestType == RequestType::Dump) {
> +    CodeCoverageHandler::DumpCounters(0);
> +  } else if (requestType == RequestType::Reset) {
> +    CodeCoverageHandler::ResetCounters(0);

What are these bare zeros here?  I know this is kind of pre-existing code, but a comment on them would be nice, at least.

@@ +59,5 @@
> +    for (auto* cp : ContentParent::AllProcesses(ContentParent::eLive)) {
> +      if (requestType == RequestType::Dump) {
> +        cp->SendDumpCodeCoverageCounters()->Then(MessageLoop::current()->SerialEventTarget(), __func__, [processCount, promise](bool unused) mutable {
> +          processCount--;
> +          if (processCount == 0) {

Does this actually do what you want?  I don't see how, because either:

a) You capture processCount by reference, in which case you're referring to some slot on the stack that's going away when Request() returns, and will get overwritten by who knows what later; or
b) You capture processCount by value, in which case each promise has its own copy of processCount, and they're not decrementing a shared value.  So it will work by happenstance when processCount is 1, but will fail for all other values.

Or does this magically work because I am missing something?  Either way, this is one of those reasons that it would be nice if we didn't duplicate code blocks here.

I think you have to allocate some shared integer which everything can decrement, and then the last one out can deallocate.  Oh, and that means you have to handle deallocation in case of rejection too.  Perhaps there's a better way to solve this?

Comment 5

[Marco Castelluccio [:marco]]

(In reply to Nathan Froyd [:froydnj] from comment #4)
> I would be interested to see what the C++ errors looked like; the
> duplication of code there is really unfortunate.

I'll upload the log later.

> ::: tools/code-coverage/nsCodeCoverage.cpp
> @@ +49,5 @@
> > +
> > +  if (requestType == RequestType::Dump) {
> > +    CodeCoverageHandler::DumpCounters(0);
> > +  } else if (requestType == RequestType::Reset) {
> > +    CodeCoverageHandler::ResetCounters(0);
> 
> What are these bare zeros here?  I know this is kind of pre-existing code,
> but a comment on them would be nice, at least.

It's because they are also signal handlers. I guess I could create a new function without parameters that would be called here and by the signal handler.

> 
> @@ +59,5 @@
> > +    for (auto* cp : ContentParent::AllProcesses(ContentParent::eLive)) {
> > +      if (requestType == RequestType::Dump) {
> > +        cp->SendDumpCodeCoverageCounters()->Then(MessageLoop::current()->SerialEventTarget(), __func__, [processCount, promise](bool unused) mutable {
> > +          processCount--;
> > +          if (processCount == 0) {
> 
> Does this actually do what you want?  I don't see how, because either:
> 
> a) You capture processCount by reference, in which case you're referring to
> some slot on the stack that's going away when Request() returns, and will
> get overwritten by who knows what later; or
> b) You capture processCount by value, in which case each promise has its own
> copy of processCount, and they're not decrementing a shared value.  So it
> will work by happenstance when processCount is 1, but will fail for all
> other values.
> 
> Or does this magically work because I am missing something?  Either way,
> this is one of those reasons that it would be nice if we didn't duplicate
> code blocks here.
> 
> I think you have to allocate some shared integer which everything can
> decrement, and then the last one out can deallocate.  Oh, and that means you
> have to handle deallocation in case of rejection too.  Perhaps there's a
> better way to solve this?

I thought a single object corresponding to the lambda would be created here, with processCount as a kind of property. Let me see if I can write a simple example to check.

Another option would be to use a static integer.

Yet another option might be to create a class storing a count and use RefPtr<ProcessCount>.

Comment 6

[Marco Castelluccio [:marco]]

Attachment: log.txt

(In reply to Marco Castelluccio [:marco] from comment #5)
> (In reply to Nathan Froyd [:froydnj] from comment #4)
> > I would be interested to see what the C++ errors looked like; the
> > duplication of code there is really unfortunate.
> 
> I'll upload the log later.

I'm attaching the logs.

> > 
> > @@ +59,5 @@
> > > +    for (auto* cp : ContentParent::AllProcesses(ContentParent::eLive)) {
> > > +      if (requestType == RequestType::Dump) {
> > > +        cp->SendDumpCodeCoverageCounters()->Then(MessageLoop::current()->SerialEventTarget(), __func__, [processCount, promise](bool unused) mutable {
> > > +          processCount--;
> > > +          if (processCount == 0) {
> > 
> > Does this actually do what you want?  I don't see how, because either:
> > 
> > a) You capture processCount by reference, in which case you're referring to
> > some slot on the stack that's going away when Request() returns, and will
> > get overwritten by who knows what later; or
> > b) You capture processCount by value, in which case each promise has its own
> > copy of processCount, and they're not decrementing a shared value.  So it
> > will work by happenstance when processCount is 1, but will fail for all
> > other values.
> > 
> > Or does this magically work because I am missing something?  Either way,
> > this is one of those reasons that it would be nice if we didn't duplicate
> > code blocks here.
> > 
> > I think you have to allocate some shared integer which everything can
> > decrement, and then the last one out can deallocate.  Oh, and that means you
> > have to handle deallocation in case of rejection too.  Perhaps there's a
> > better way to solve this?
> 
> I thought a single object corresponding to the lambda would be created here,
> with processCount as a kind of property. Let me see if I can write a simple
> example to check.
> 
> Another option would be to use a static integer.
> 
> Yet another option might be to create a class storing a count and use
> RefPtr<ProcessCount>.

Yeah, it appears to work:
> #include <iostream>
> using namespace std;
> 
> int main() {
>   uint32_t val = 0;
>   auto lambda = [val]() mutable { cout << "Lambda: " << val << endl; return ++val;};
>   lambda();
>   lambda();
>   lambda();
>   lambda();
>   lambda();
>   return 0;
> }
prints:
> Lambda: 0
> Lambda: 1
> Lambda: 2
> Lambda: 3
> Lambda: 4

Comment 7

[Nathan Froyd [:froydnj]]

Thanks for the logs.  That's quite the error.  I'll have to look at that later when I can stare at it a little longer.

(In reply to Marco Castelluccio [:marco] from comment #6)
> > #include <iostream>
> > using namespace std;
> > 
> > int main() {
> >   uint32_t val = 0;
> >   auto lambda = [val]() mutable { cout << "Lambda: " << val << endl; return ++val;};
> >   lambda();
> >   lambda();
> >   lambda();
> >   lambda();
> >   lambda();
> >   return 0;
> > }
> prints:
> > Lambda: 0
> > Lambda: 1
> > Lambda: 2
> > Lambda: 3
> > Lambda: 4

Is this the same thing as the example in the patch?  Don't the lambdas in the patch outlive the scope of the function in which they were created?

Comment 8

[Marco Castelluccio [:marco]]

(In reply to Nathan Froyd [:froydnj] from comment #7)
> Thanks for the logs.  That's quite the error.  I'll have to look at that
> later when I can stare at it a little longer.

Thanks!

> (In reply to Marco Castelluccio [:marco] from comment #6)
> > > #include <iostream>
> > > using namespace std;
> > > 
> > > int main() {
> > >   uint32_t val = 0;
> > >   auto lambda = [val]() mutable { cout << "Lambda: " << val << endl; return ++val;};
> > >   lambda();
> > >   lambda();
> > >   lambda();
> > >   lambda();
> > >   lambda();
> > >   return 0;
> > > }
> > prints:
> > > Lambda: 0
> > > Lambda: 1
> > > Lambda: 2
> > > Lambda: 3
> > > Lambda: 4
> 
> Is this the same thing as the example in the patch?  Don't the lambdas in
> the patch outlive the scope of the function in which they were created?

I think it should work anyway (provided we can share the code so that we create the lambda once and not for every iteration of the loop), as the value is copied, so it should now be unrelated to the function which created it.
E.g.:
> #include <iostream>
> using namespace std;
> 
> auto f() {
>   uint32_t val = 0;
>   auto ret = [val]() mutable { cout << "Lambda: " << val << endl; return ++val;};
>   val = 10;
>   cout << "Val: " << val << endl;
>   return ret;
> }
> 
> int main() {
>   auto lambda = f();
>   cout << "Start" << endl;
>   lambda();
>   lambda();
>   lambda();
>   lambda();
>   lambda();
>   return 0;
> }
prints:
> Val: 10
> Start
> Lambda: 0
> Lambda: 1
> Lambda: 2
> Lambda: 3
> Lambda: 4

Comment 9

[Nathan Froyd [:froydnj]]

Yes, but e.g.:

#include <stdio.h>
#include <stdint.h>

#include <vector>
#include <functional>

using namespace std;

auto f() {
  uint32_t val = 0;
  auto ret = [val]() mutable { printf("Lambda %u\n", val); return ++val;};
  auto ret2 = [val]() mutable { printf("Lambda %u\n", val); return ++val;};
  val = 10;
  vector<function<uint32_t()>> v;
  v.push_back(ret);
  v.push_back(ret2);
  printf("Val: %u\n", val);
  return v;
}

int main() {
  auto v = f();
  printf("Start\n");
  for (int i = 0; i < 5; i++) {
    for (auto& l : v) {
      l();
    }
  }
  return 0;
}

prints:

Val: 10
Start
Lambda 0
Lambda 0
Lambda 1
Lambda 1
Lambda 2
Lambda 2
Lambda 3
Lambda 3
Lambda 4
Lambda 4

when AIUI you really want the lambdas sharing val.

Comment 10

[Marco Castelluccio [:marco]]

(In reply to Nathan Froyd [:froydnj] from comment #9)
> Yes, but e.g.:
> 
> ...
> 
> when AIUI you really want the lambdas sharing val.

Yes, it would only work if we fix the problem preventing us from creating the lambda once and not for every iteration of the loop.

Comment 11

[Nathan Froyd [:froydnj]]

(In reply to Marco Castelluccio [:marco] from comment #10)
> (In reply to Nathan Froyd [:froydnj] from comment #9)
> > Yes, but e.g.:
> > 
> > ...
> > 
> > when AIUI you really want the lambdas sharing val.
> 
> Yes, it would only work if we fix the problem preventing us from creating
> the lambda once and not for every iteration of the loop.

That seems like it just moves the problem around: who owns the lone lambda now?  Where does the lambda live?  I guess you could package the lambda up in a NewRunnableFunction, just so you get something that could be conveniently shared.

I haven't seen the code the log is referring to, but I'm imagining that's the problem the compiler error messages are (poorly) pointing out: you're trying to pass in a reference to a thing to a place that wants a wholly-owned thing:

 0:07.52 /home/marco/Documenti/FD/mozilla-unified/obj-gcc-ccov/dist/include/mozilla/MozPromise.h:997:7: error: cannot bind non-const lvalue reference of type ‘Request(JSContext*, mozilla::dom::Promise**, RequestType)::<lambda(mozilla::ipc::ResponseRejectReason)>&’ to an rvalue of type ‘std::remove_reference<Request(JSContext*, mozilla::dom::Promise**, RequestType)::<lambda(mozilla::ipc::ResponseRejectReason)>&>::type {aka Request(JSContext*, mozilla::dom::Promise**, RequestType)::<lambda(mozilla::ipc::ResponseRejectReason)>}’
 0:07.52        new ThenValueType(aResponseTarget, std::move(aFunctions)..., aCallSite);
 0:07.52        ^~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
 0:07.52 /home/marco/Documenti/FD/mozilla-unified/obj-gcc-ccov/dist/include/mozilla/MozPromise.h:738:5: note:   initializing argument 3 of ‘mozilla::MozPromise<ResolveValueT, RejectValueT, IsExclusive>::ThenValue<ResolveFunction, RejectFunction>::ThenValue(nsISerialEventTarget*, ResolveFunction&&, RejectFunction&&, const char*) [with ResolveFunction = Request(JSContext*, mozilla::dom::Promise**, RequestType)::<lambda(bool)>; RejectFunction = Request(JSContext*, mozilla::dom::Promise**, RequestType)::<lambda(mozilla::ipc::ResponseRejectReason)>&; ResolveValueT = bool; RejectValueT = mozilla::ipc::ResponseRejectReason; bool IsExclusive = false]’
 0:07.52      ThenValue(nsISerialEventTarget* aResponseTarget,
 0:07.52      ^~~~~~~~~

Comment 12

[Marco Castelluccio [:marco]]

(In reply to Nathan Froyd [:froydnj] from comment #11)
> (In reply to Marco Castelluccio [:marco] from comment #10)
> > (In reply to Nathan Froyd [:froydnj] from comment #9)
> > > Yes, but e.g.:
> > > 
> > > ...
> > > 
> > > when AIUI you really want the lambdas sharing val.
> > 
> > Yes, it would only work if we fix the problem preventing us from creating
> > the lambda once and not for every iteration of the loop.
> 
> That seems like it just moves the problem around: who owns the lone lambda
> now?  Where does the lambda live?  I guess you could package the lambda up
> in a NewRunnableFunction, just so you get something that could be
> conveniently shared.
> 
> I haven't seen the code the log is referring to, but I'm imagining that's
> the problem the compiler error messages are (poorly) pointing out: you're
> trying to pass in a reference to a thing to a place that wants a
> wholly-owned thing:

I couldn't use NewRunnableFunction as it only supports functions with no parameters. I've found that the other API for async returns (without "->Then(") actually takes ownership of the lambda (by copy I think), so I can use that.

Comment 13

[Marco Castelluccio [:marco]]

Attachment: Part 1: Make dumpCoverage and resetCoverage return a Promise that is resolved when the parent process and all content processes are done with dumping or resetting coverage counters

Comment 14

[Nathan Froyd [:froydnj]]

Comment on attachment 8987700 [details] [diff] [review]
Part 1: Make dumpCoverage and resetCoverage return a Promise that is resolved when the parent process and all content processes are done with dumping or resetting coverage counters

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

This looks better, thank you.

::: tools/code-coverage/nsCodeCoverage.cpp
@@ +25,5 @@
>  }
>  
> +enum RequestType { Dump, Reset };
> +
> +class ProcessCount {

Please make this class final.

@@ +60,2 @@
>    for (auto* cp : ContentParent::AllProcesses(ContentParent::eLive)) {
> +    ++(*processCount);

I am a slight fan of just accumulating into a local uint32_t and constructing a ProcessCount down in the else branch, below, where it's needed.  Also means that ProcessCount doesn't need operator++.

But it probably doesn't matter too much.

Comment 15

[Marco Castelluccio [:marco]]

Attachment: Part 1: Make dumpCoverage and resetCoverage return a Promise that is resolved when the parent process and all content processes are done with dumping or resetting coverage counters

Thanks for the help! I think this is now ready for review.

Comment 16

[Marco Castelluccio [:marco]]

Attachment: Part 2: Add a PerTestCoverageUtils JavaScript module to manage resetting/dumping coverage counters for tests

This module is meant to be used by the harnesses to implement resetting/dumping at the right time.

Comment 17

[Marco Castelluccio [:marco]]

Attachment: Part 3: Support resetting/dumping coverage counters in per-test mode for xpcshell on Linux

This makes use of the module from Part 2 to implement resetting the counters before running an xpcshell test and dumping the counters after the test and before shutting down the browser.

It is only implemented for xpcshell for now, after which we can test it on CI, get the data in ActiveData and evaluate if it improves things.

Comment 18

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

pushing these to try to see if there is an improvement we can see:
https://treeherder.mozilla.org/#/jobs?repo=try&author=[e-mail]&fromchange=c64fc984fc51c15f26e3560704369a2c5491d229&tochange=6c980d186cc39ae02300b8934cc536e79db6abc3

NOTE: there are some eslint and flake8 failures that would need to be corrected.

Comment 19

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

this fails to run properly:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=6c980d186cc39ae02300b8934cc536e79db6abc3

do submit for review again when things are looking better.

Comment 20

[Marco Castelluccio [:marco]]

Attachment: Part 2: Add a PerTestCoverageUtils JavaScript module to manage resetting/dumping coverage counters for tests

This should fix the eslint failure.

Comment 21

[Marco Castelluccio [:marco]]

Attachment: Part 3: Support resetting/dumping coverage counters in per-test mode for xpcshell on Linux

This should fix the flake8 failure (which was actually a bug, 'tempfile' was not imported).

Comment 22

[Marco Castelluccio [:marco]]

I've pushed the patches to try, the reports got quite smaller.
devtools/client/shared/test/unit/test_unicode-url.js from ~655 kB to ~228 kB.
devtools/server/tests/unit/test_objectgrips-09.js from ~1,9 MB to ~1,5 MB.
devtools/client/memory/test/unit/test_action-clear-snapshots_03.js from ~2 MB to ~1,5 MB.
chrome/test/unit/test_bug401153.js from ~527 kB to ~115 kB.

I will fix one thing first (not resetting/dumping for baseline test), and then I'll resubmit part 2 and part 3 for review.

Comment 23

[Marco Castelluccio [:marco]]

Attachment: Part 2: Add a PerTestCoverageUtils JavaScript module to manage resetting/dumping coverage counters for tests

Comment 24

[Marco Castelluccio [:marco]]

Attachment: Part 3: Support resetting/dumping coverage counters in per-test mode for xpcshell on Linux

Comment 25

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

Comment on attachment 8988142 [details] [diff] [review]
Part 2: Add a PerTestCoverageUtils JavaScript module to manage resetting/dumping coverage counters for tests

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

this looks pretty straightforward

Comment 26

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

Comment on attachment 8988143 [details] [diff] [review]
Part 3: Support resetting/dumping coverage counters in per-test mode for xpcshell on Linux

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

2 small things.

::: testing/mozharness/scripts/desktop_unittest.py
@@ +893,5 @@
>                          gcov_dir, jsvm_dir = self.set_coverage_env(env)
> +                        # Per-test reset/dump is only supported for xpcshell and
> +                        # Linux for the time being.
> +                        if not is_baseline_test and suite == 'xpcshell' and self._is_linux():
> +                            env['GCOV_RESULTS_DIR'] = tempfile.mkdtemp()

could we also set |env['GCOV_RESULTS_DIR'] = gcov_dir = tempfile.mkdtemp()| ?

then that would simplify the change (actually get rid of it) to the args in add_per_test_coverage_report()

::: testing/xpcshell/head.js
@@ +517,5 @@
> +    // If the module doesn't exist, code coverage is disabled.
> +    // Otherwise, rethrow the exception.
> +    if (e.result != Cr.NS_ERROR_FILE_NOT_FOUND) {
> +      throw e;
> +    }

will we get a realistic error message in the log file so we can discover that there was an error importing PerTestcoverageUtils?

Comment 27

[Marco Castelluccio [:marco]]

(In reply to Joel Maher ( :jmaher ) (UTC-4) from comment #26)
> ::: testing/mozharness/scripts/desktop_unittest.py
> @@ +893,5 @@
> >                          gcov_dir, jsvm_dir = self.set_coverage_env(env)
> > +                        # Per-test reset/dump is only supported for xpcshell and
> > +                        # Linux for the time being.
> > +                        if not is_baseline_test and suite == 'xpcshell' and self._is_linux():
> > +                            env['GCOV_RESULTS_DIR'] = tempfile.mkdtemp()
> 
> could we also set |env['GCOV_RESULTS_DIR'] = gcov_dir = tempfile.mkdtemp()| ?
> 
> then that would simplify the change (actually get rid of it) to the args in
> add_per_test_coverage_report()

Good idea, I've done that!

> 
> ::: testing/xpcshell/head.js
> @@ +517,5 @@
> > +    // If the module doesn't exist, code coverage is disabled.
> > +    // Otherwise, rethrow the exception.
> > +    if (e.result != Cr.NS_ERROR_FILE_NOT_FOUND) {
> > +      throw e;
> > +    }
> 
> will we get a realistic error message in the log file so we can discover
> that there was an error importing PerTestcoverageUtils?

Yes, I've tried to inject a syntax error in the file and this is what I got:
>  0:01.07 pid:15037 JavaScript error: resource://testing-common/PerTestCoverageUtils.jsm, line 58: SyntaxError: unexpected token: identifier

Comment 28

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

oh that error looks good :)

Comment 29

[Marco Castelluccio [:marco]]

Attachment: Part 3: Support resetting/dumping coverage counters in per-test mode for xpcshell on Linux

Carrying r+.

Comment 30

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/ddde7dd347d4
Make dumpCoverage and resetCoverage return a Promise that is resolved when the parent process and all content processes are done with dumping or resetting coverage counters. r=froydnj
https://hg.mozilla.org/integration/mozilla-inbound/rev/3579431e03dc
Add a PerTestCoverageUtils JavaScript module to manage resetting/dumping coverage counters for tests. r=jmaher
https://hg.mozilla.org/integration/mozilla-inbound/rev/c73f394a4bef
Support resetting/dumping coverage counters in per-test mode for xpcshell on Linux. r=jmaher

Comment 31

[Cristina Coroiu [:ccoroiu]]

Backed out 3 changesets (bug 1470151) for build bustage at testing/xpcshell/selftest.py 

Backout: https://hg.mozilla.org/integration/mozilla-inbound/rev/194d57fb47585d05b90efbedf85fb61fc6c9084e

Failure push: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=c73f394a4bef01cccd76d635bce9d67e4a48f721

Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=185163031&repo=mozilla-inbound&lineNumber=37354

[task 2018-06-27T13:49:41.768Z] 13:49:41     INFO - /builds/worker/workspace/build/src/python/mozbuild/mozbuild/test/configure/test_moz_configure.py
[task 2018-06-27T13:49:41.769Z] 13:49:41     INFO - ============================= test session starts ==============================
[task 2018-06-27T13:49:41.769Z] 13:49:41     INFO - platform linux2 -- Python 2.7.9, pytest-3.2.5, py-1.5.3, pluggy-0.4.0 -- /builds/worker/workspace/build/src/obj-firefox/_virtualenvs/src-UL-dti-o/bin/python
[task 2018-06-27T13:49:41.769Z] 13:49:41     INFO - rootdir: /builds/worker/workspace/build/src/python/mozbuild/mozbuild/test/configure, inifile: /builds/worker/workspace/build/src/config/mozunit/mozunit/pytest.ini
[task 2018-06-27T13:49:41.769Z] 13:49:41     INFO - collecting ... collected 2 items
[task 2018-06-27T13:49:41.769Z] 13:49:41     INFO - ../python/mozbuild/mozbuild/test/configure/test_moz_configure.py::TestMozConfigure::test_moz_configure_options PASSED
[task 2018-06-27T13:49:41.770Z] 13:49:41     INFO - ../python/mozbuild/mozbuild/test/configure/test_moz_configure.py::TestMozConfigure::test_nsis_version PASSED
[task 2018-06-27T13:49:41.770Z] 13:49:41     INFO - =========================== 2 passed in 7.19 seconds ===========================
[task 2018-06-27T13:50:23.552Z] 13:50:23     INFO - /builds/worker/workspace/build/src/testing/xpcshell/selftest.py
[task 2018-06-27T13:50:23.553Z] 13:50:23     INFO - ============================= test session starts ==============================
[task 2018-06-27T13:50:23.553Z] 13:50:23     INFO - platform linux2 -- Python 2.7.9, pytest-3.2.5, py-1.5.3, pluggy-0.4.0 -- /builds/worker/workspace/build/src/obj-firefox/_virtualenvs/src-UL-dti-o/bin/python
[task 2018-06-27T13:50:23.553Z] 13:50:23     INFO - rootdir: /builds/worker/workspace/build/src/testing/xpcshell, inifile: /builds/worker/workspace/build/src/config/mozunit/mozunit/pytest.ini
[task 2018-06-27T13:50:23.553Z] 13:50:23     INFO - collecting ... collected 55 items
[task 2018-06-27T13:50:23.553Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTaskRunNextTest PASSED
[task 2018-06-27T13:50:23.553Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTaskSkip TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.553Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTaskSkipAll TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.554Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTaskStackTrace TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.554Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTaskTestFailureInside PASSED
[task 2018-06-27T13:50:23.554Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTaskTestMultiple TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.554Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTaskTestRejected PASSED
[task 2018-06-27T13:50:23.554Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTaskTestSingle TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.554Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTestFailing PASSED
[task 2018-06-27T13:50:23.554Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTestSimple TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.555Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTestUncaughtRejection PASSED
[task 2018-06-27T13:50:23.555Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAddTestUncaughtRejectionJSM PASSED
[task 2018-06-27T13:50:23.555Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAssertStack <- ../../../../../../../usr/lib/python2.7/unittest/case.py SKIPPED
[task 2018-06-27T13:50:23.555Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testAsyncCleanup TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.555Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testChild TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.555Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testChildFail TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.555Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testChildHang TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.555Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testChildMozinfo TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.556Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testChildPass TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.556Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testDoPrintWhenVerboseExplicit TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.556Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testDoPrintWhenVerboseInManifest TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.556Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testDoPrintWhenVerboseNotExplicit TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.556Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testDoReportForeignObject TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.556Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testDoReportNonSyntaxError PASSED
[task 2018-06-27T13:50:23.556Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testDoReportRefError TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.557Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testDoReportSyntaxError PASSED
[task 2018-06-27T13:50:23.557Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testDoThrowForeignObject TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.557Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testDoThrowString TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.557Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testFail PASSED
[task 2018-06-27T13:50:23.557Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testHangingTimeout <- ../../../../../../../usr/lib/python2.7/unittest/case.py SKIPPED
[task 2018-06-27T13:50:23.557Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testKnownFail PASSED
[task 2018-06-27T13:50:23.557Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testLogCorrectFileName TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.558Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testMissingHeadFile PASSED
[task 2018-06-27T13:50:23.558Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testMozinfo TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.558Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testNoRunTestAddTask TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.558Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testNoRunTestAddTaskFail PASSED
[task 2018-06-27T13:50:23.558Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testNoRunTestAddTaskMultiple TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.558Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testNoRunTestAddTest TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.558Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testNoRunTestAddTestAddTask TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.558Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testNoRunTestAddTestFail PASSED
[task 2018-06-27T13:50:23.559Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testNoRunTestEmptyTest TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.559Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testNotSkipForAddTask TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.559Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testNotSkipForAddTest TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.559Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testPass TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.559Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testPassFail TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.559Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testRandomExecution TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.559Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testReturnNonzero PASSED
[task 2018-06-27T13:50:23.560Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testSkip PASSED
[task 2018-06-27T13:50:23.560Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testSkipForAddTask TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.560Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testSkipForAddTest TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.560Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testSyntaxError PASSED
[task 2018-06-27T13:50:23.560Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testUncaughtRejection TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.560Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testUncaughtRejectionJSM TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.560Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testUnexpectedPass TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.561Z] 13:50:23  WARNING - ../testing/xpcshell/selftest.py::XPCShellTestsTests::testUnicodeInAssertMethods TEST-UNEXPECTED-FAIL
[task 2018-06-27T13:50:23.561Z] 13:50:23     INFO - =================================== FAILURES ===================================
[task 2018-06-27T13:50:23.561Z] 13:50:23     INFO - ______________________ XPCShellTestsTests.testAddTaskSkip ______________________
[task 2018-06-27T13:50:23.561Z] 13:50:23     INFO - self = <selftest.XPCShellTestsTests testMethod=testAddTaskSkip>
[task 2018-06-27T13:50:23.561Z] 13:50:23     INFO -     def testAddTaskSkip(self):
[task 2018-06-27T13:50:23.561Z] 13:50:23     INFO -         self.writeFile("test_tasks_skip.js", ADD_TASK_SKIP)
[task 2018-06-27T13:50:23.561Z] 13:50:23     INFO -         self.writeManifest(["test_tasks_skip.js"])
[task 2018-06-27T13:50:23.561Z] 13:50:23     INFO - >       self.assertTestResult(True)
[task 2018-06-27T13:50:23.561Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py:1067:
[task 2018-06-27T13:50:23.562Z] 13:50:23     INFO - _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _
[task 2018-06-27T13:50:23.562Z] 13:50:23     INFO - ../testing/xpcshell/selftest.py:527: in assertTestResult
[task 2018-06-27T13:50:23.562Z] 13:50:23     INFO -     """ % ("passed" if expected else "failed", self.log.getvalue()))
[task 2018-06-27T13:50:23.562Z] 13:50:23     INFO - E   AssertionError: Tests should have passed, log:
[task 2018-06-27T13:50:23.562Z] 13:50:23     INFO - E   ========
[task 2018-06-27T13:50:23.562Z] 13:50:23     INFO - E   runxpcshelltests.py | using symbolizer at /builds/worker/workspace/build/src/obj-firefox/dist/bin/llvm-symbolizer
[task 2018-06-27T13:50:23.562Z] 13:50:23     INFO - E   MOZ_NODE_PATH environment variable not set. Tests requiring http/2 will fail.
[task 2018-06-27T13:50:23.562Z] 13:50:23     INFO - E   Running tests sequentially.
[task 2018-06-27T13:50:23.562Z] 13:50:23     INFO - E   SUITE-START | Running 1 tests
[task 2018-06-27T13:50:23.562Z] 13:50:23     INFO - E   TEST-START | test_tasks_skip.js
[task 2018-06-27T13:50:23.563Z] 13:50:23  WARNING - E   TEST-UNEXPECTED-FAIL | test_tasks_skip.js | xpcshell return code: 1

Comment 32

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/e3bb0b8bed89
Make dumpCoverage and resetCoverage return a Promise that is resolved when the parent process and all content processes are done with dumping or resetting coverage counters. r=froydnj
https://hg.mozilla.org/integration/mozilla-inbound/rev/a84d5258fce5
Add a PerTestCoverageUtils JavaScript module to manage resetting/dumping coverage counters for tests. r=jmaher
https://hg.mozilla.org/integration/mozilla-inbound/rev/ad943a10a01d
Support resetting/dumping coverage counters in per-test mode for xpcshell on Linux. r=jmaher

Comment 33

[Cristina Coroiu [:ccoroiu]]

Also the xpcshell was failing on Android:
https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=c73f394a4bef01cccd76d635bce9d67e4a48f721&filter-searchStr=xpcshell&selectedJob=185169239

Failure log:https://treeherder.mozilla.org/logviewer.html#?job_id=185170309&repo=mozilla-inbound&lineNumber=1205

[task 2018-06-27T14:03:54.724Z] 14:03:54     INFO -  TEST-START | caps/tests/unit/test_origin.js
[task 2018-06-27T14:03:58.139Z] 14:03:58  WARNING -  TEST-UNEXPECTED-FAIL | caps/tests/unit/test_origin.js | xpcshell return code: 139
[task 2018-06-27T14:03:58.139Z] 14:03:58     INFO -  TEST-INFO took 3414ms
[task 2018-06-27T14:03:58.139Z] 14:03:58     INFO -  >>>>>>>
[task 2018-06-27T14:03:58.140Z] 14:03:58     INFO -  caps/tests/unit/test_origin.js | xpcw: cd /sdcard/tests/xpc/caps/tests/unit
[task 2018-06-27T14:03:58.141Z] 14:03:58     INFO -  caps/tests/unit/test_origin.js | xpcw: xpcshell -r /sdcard/tests/xpc/c/httpd.manifest --greomni /data/local/xpcb/target.apk -m -s -e const _HEAD_JS_PATH = "/sdcard/tests/xpc/head.js"; -e const _MOZINFO_JS_PATH = "/sdcard/tests/xpc/p/mozinfo.json"; -e const _TESTING_MODULES_DIR = "/sdcard/tests/xpc/m"; -f /sdcard/tests/xpc/head.js -e const _SERVER_ADDR = "localhost" -e const _HEAD_FILES = []; -e const _JSDEBUGGER_PORT = 0; -e const _TEST_FILE = ["test_origin.js"]; -e const _TEST_NAME = "caps/tests/unit/test_origin.js" -e _execute_test(); quit(0);
[task 2018-06-27T14:03:58.141Z] 14:03:58     INFO -  caps/tests/unit/test_origin.js | JavaScript error: /sdcard/tests/xpc/head.js, line 524: ReferenceError: PerTestCoverageUtils is not defined
[task 2018-06-27T14:03:58.141Z] 14:03:58     INFO -  caps/tests/unit/test_origin.js | Segmentation fault
[task 2018-06-27T14:03:58.142Z] 14:03:58     INFO -  <<<<<<<
[task 2018-06-27T14:03:58.552Z] 14:03:58     INFO -  mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/KXKdmTJjTr2l4anpd2r-vQ/artifacts/public/build/target.crashreporter-symbols.zip
[task 2018-06-27T14:04:02.512Z] 14:04:02     INFO -  mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpZFbVZY/21fc8be9-521f-527d-0c88-5078fb3b2945.dmp /tmp/tmpJn7F3E
[task 2018-06-27T14:04:09.482Z] 14:04:09     INFO -  mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/21fc8be9-521f-527d-0c88-5078fb3b2945.dmp
[task 2018-06-27T14:04:09.482Z] 14:04:09     INFO -  mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/21fc8be9-521f-527d-0c88-5078fb3b2945.extra
[task 2018-06-27T14:04:09.483Z] 14:04:09  WARNING -  PROCESS-CRASH | caps/tests/unit/test_origin.js | application crashed [@ NS_CycleCollectorSuspect3]
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -  Crash dump filename: /tmp/tmpZFbVZY/21fc8be9-521f-527d-0c88-5078fb3b2945.dmp
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -  Operating system: Android
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -                    0.0.0 Linux 2.6.29-gea477bb #1 Wed Sep 26 11:04:45 PDT 2012 armv7l
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -  CPU: arm
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -       ARMv7 ARM Cortex-A8 features: swp,half,thumb,fastmult,vfpv2,edsp,neon,vfpv3
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -       1 CPU
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -  GPU: UNKNOWN
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -  Crash reason:  SIGSEGV
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -  Crash address: 0x0
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -  Process uptime: not available
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -  Thread 0 (crashed)
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -   0  libxul.so!NS_CycleCollectorSuspect3 [RefPtr.h:c73f394a4bef01cccd76d635bce9d67e4a48f721 : 321 + 0x0]
[task 2018-06-27T14:04:09.487Z] 14:04:09     INFO -       r0 = 0x00000000    r1 = 0x00000000    r2 = 0x00000015    r3 = 0x0000001c
[task 2018-06-27T14:04:09.488Z] 14:04:09     INFO -       r4 = 0x00000000    r5 = 0x51068d64    r6 = 0x51068d60    r7 = 0xbee56380
[task 2018-06-27T14:04:09.488Z] 14:04:09     INFO -       r8 = 0x00000000    r9 = 0x00000000   r10 = 0x4568f39c   r12 = 0x44005528
[task 2018-06-27T14:04:09.489Z] 14:04:09     INFO -       fp = 0x00000016    sp = 0xbee56358    lr = 0x406c4cef    pc = 0x406c4cee
[task 2018-06-27T14:04:09.489Z] 14:04:09     INFO -      Found by: given as instruction pointer in context

Comment 34

[Marco Castelluccio [:marco]]

I've fixed the issue and re-pushed.

Comment 35

[Tiberius Oros[:tiberius_oros]]

https://hg.mozilla.org/mozilla-central/rev/e3bb0b8bed89
https://hg.mozilla.org/mozilla-central/rev/a84d5258fce5
https://hg.mozilla.org/mozilla-central/rev/ad943a10a01d