1075240 - The mochitest harness should log disabled tests as test_start/test_end with status 'SKIP'

Status: RESOLVED FIXED

(Testing :: Mochitest, defect)

Description

[Chris Manchester (limited bugmail, email directly)]

I'm replacing some things mozharness that summarize test counts with structured log data, and I just realized we weren't doing this already.

Comment 1

[Chris Manchester (limited bugmail, email directly)]

Attachment: Log disabled tests as skips in mochitests.

https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=51455bfdb770

Comment 2

[Chris Manchester (limited bugmail, email directly)]

I had to fix bug 1060439 along the way.

Comment 3

[Andrew Halberstadt [:ahal]]

Comment on attachment 8498903 [details] [diff] [review]
Log disabled tests as skips in mochitests.

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

I'm kind of hesitant about this because it is filling the log with redundant information, but I guess it's not that big of a deal.

::: testing/mochitest/runtests.py
@@ +1620,5 @@
> +    self.log.suite_start([t['path'] for t in tests])
> +    for test in tests:
> +      if 'disabled' in test:
> +        self.log.test_start(test['path'])
> +        self.log.test_end(test['path'], 'SKIP', message=test['disabled'])

It's unfortunate that we are populating the log with redundant test_start messages. How hard would it be to get the formatter to not log test_start in this case?

::: testing/mochitest/runtestsb2g.py
@@ +112,5 @@
>      def run_tests(self, options):
>          """ Prepare, configure, run tests and cleanup """
>  
>          manifest = self.build_profile(options)
> +        self.logPreamble(self.getActiveTests(options))

This looks like it won't log skipped tests.. is that correct?

Comment 4

[Chris Manchester (limited bugmail, email directly)]

(In reply to Andrew Halberstadt [:ahal] from comment #3)
> Comment on attachment 8498903 [details] [diff] [review]
> Log disabled tests as skips in mochitests.
> 
> Review of attachment 8498903 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> I'm kind of hesitant about this because it is filling the log with redundant
> information, but I guess it's not that big of a deal.
> 
> ::: testing/mochitest/runtests.py
> @@ +1620,5 @@
> > +    self.log.suite_start([t['path'] for t in tests])
> > +    for test in tests:
> > +      if 'disabled' in test:
> > +        self.log.test_start(test['path'])
> > +        self.log.test_end(test['path'], 'SKIP', message=test['disabled'])
> 
> It's unfortunate that we are populating the log with redundant test_start
> messages. How hard would it be to get the formatter to not log test_start in
> this case?

Logging test_start/test_end with status 'SKIP' is the way to expose this from mozlog... it would be wonky to try to surpress the test_start messages, because somehow we'd have to stuff the fact it's a SKIP into the test start call.

> 
> ::: testing/mochitest/runtestsb2g.py
> @@ +112,5 @@
> >      def run_tests(self, options):
> >          """ Prepare, configure, run tests and cleanup """
> >  
> >          manifest = self.build_profile(options)
> > +        self.logPreamble(self.getActiveTests(options))
> 
> This looks like it won't log skipped tests.. is that correct?

Oh, I think that's a bug. Thanks.

Comment 5

[Chris Manchester (limited bugmail, email directly)]

(In reply to Chris Manchester [:chmanchester] from comment #4)
> (In reply to Andrew Halberstadt [:ahal] from comment #3)
> > Comment on attachment 8498903 [details] [diff] [review]
> > Log disabled tests as skips in mochitests.
> > 
> > Review of attachment 8498903 [details] [diff] [review]:
> > -----------------------------------------------------------------
> > 
> > I'm kind of hesitant about this because it is filling the log with redundant
> > information, but I guess it's not that big of a deal.
> > 
> > ::: testing/mochitest/runtests.py
> > @@ +1620,5 @@
> > > +    self.log.suite_start([t['path'] for t in tests])
> > > +    for test in tests:
> > > +      if 'disabled' in test:
> > > +        self.log.test_start(test['path'])
> > > +        self.log.test_end(test['path'], 'SKIP', message=test['disabled'])
> > 
> > It's unfortunate that we are populating the log with redundant test_start
> > messages. How hard would it be to get the formatter to not log test_start in
> > this case?
> 
> Logging test_start/test_end with status 'SKIP' is the way to expose this
> from mozlog... it would be wonky to try to surpress the test_start messages,
> because somehow we'd have to stuff the fact it's a SKIP into the test start
> call.
> 
> > 
> > ::: testing/mochitest/runtestsb2g.py
> > @@ +112,5 @@
> > >      def run_tests(self, options):
> > >          """ Prepare, configure, run tests and cleanup """
> > >  
> > >          manifest = self.build_profile(options)
> > > +        self.logPreamble(self.getActiveTests(options))
> > 
> > This looks like it won't log skipped tests.. is that correct?
> 
> Oh, I think that's a bug. Thanks.

Aha, getActiveTests includes disabled tests by default, weird: http://dxr.mozilla.org/mozilla-central/source/testing/mochitest/runtests.py#1562

Comment 6

[Andrew Halberstadt [:ahal]]

(In reply to Chris Manchester [:chmanchester] from comment #4)
> Logging test_start/test_end with status 'SKIP' is the way to expose this
> from mozlog... it would be wonky to try to surpress the test_start messages,
> because somehow we'd have to stuff the fact it's a SKIP into the test start
> call.

What about some kind of suppress=[list,of,actions] fmt_option that we can apply immediately prior to logging this and remove immediately after. Probably not worth it I guess :/

Comment 7

[Chris Manchester (limited bugmail, email directly)]

(In reply to Andrew Halberstadt [:ahal] from comment #6)
> (In reply to Chris Manchester [:chmanchester] from comment #4)
> > Logging test_start/test_end with status 'SKIP' is the way to expose this
> > from mozlog... it would be wonky to try to surpress the test_start messages,
> > because somehow we'd have to stuff the fact it's a SKIP into the test start
> > call.
> 
> What about some kind of suppress=[list,of,actions] fmt_option that we can
> apply immediately prior to logging this and remove immediately after.
> Probably not worth it I guess :/

Yeah that's probably ovekill, but we could do something like that if it's a priority for the ui through fiddling with the logger's buffering settings.

Comment 8

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/58012cbee5b6

Comment 9

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/58012cbee5b6