1063535 - Provide a handler in mozlog to provide a summary and overall status for a test run

Status: RESOLVED FIXED

(Testing :: Mozbase, defect)

Description

[Chris Manchester (limited bugmail, email directly)]

Split out from bug 1024055 (comment 25 and below)

Comment 1

[Chris Manchester (limited bugmail, email directly)]

Attachment: Provide a mozlog handler to report overall status of a test run for the benefit of mozharness and others

Comment 2

[James Graham [:jgraham]]

Comment on attachment 8484976 [details] [diff] [review]
Provide a mozlog handler to report overall status of a test run for the benefit of mozharness and others

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

::: testing/mozbase/mozlog/mozlog/structured/handlers/statushandler.py
@@ +4,5 @@
> +
> +from collections import defaultdict
> +
> +# TBPL statuses taken from mozharness' buildbot.py
> +TBPL_SUCCESS = 'SUCCESS'

I really think the TBPL prefix here is something we should avoid if possible, expecially given that TBPL is on its way out. Can't we call it RUN_SUCCESS or something? I think I might also have a mild preference toward a named tuple rather than a long list of globals, but I could be convinced that I'm wrong there (my design would give an API like RUN_STATUS.SUCCESS)

@@ +12,5 @@
> +TBPL_RETRY = 'RETRY'
> +
> +# Statuses provided by the mozlog's test results. This can probably be
> +# extended for things like crashes.
> +MOZLOG_OK = 'OK'

How valuable is it to make these constants rather than just well-known strings? If we think there is an advantage we should have a constants.py file in mozlog that exports all these symbols, again using a named tuple or dictionary or something.

@@ +17,5 @@
> +MOZLOG_TEST_FAIL = 'FAIL'
> +MOZLOG_ERROR = 'ERROR'
> +
> +# Log levels that warrant an overall status of error for the run.
> +_mozlog_error_levels = ('CRITICAL', 'ERROR')

I think this is unneeded, because you could just check level <= mozlog.structured.log_levels["ERROR"]

@@ +35,5 @@
> +        self.unexpected = 0
> +        # A count of skip results (includes tests and subtests)
> +        self.skipped = 0
> +        # A count of top level tests run (test_end messages)
> +        self.count = 0

Call this test_count?

In the interests of generality it might also be nice to make this a default dict keyed by status.

@@ +66,5 @@
> +        translation from mozlog statuses is provided."""
> +        status = MOZLOG_OK
> +
> +        if self.count == 0:
> +            status = self._worst_status(status, MOZLOG_ERROR)

this seems to just be status = MOZLOG_ERROR

@@ +69,5 @@
> +        if self.count == 0:
> +            status = self._worst_status(status, MOZLOG_ERROR)
> +
> +        if self.unexpected > 0:
> +            status = self._worst_status(status, MOZLOG_TEST_FAIL)

It seems like if you moved this above anything that sets the status to ERROR we could just have

if self.unexpected:
    status = "FAIL"

if not self.test_count:
    status = "ERROR"

for error_level in (key for key,value in log_levels.iteritems() if value <= log_levels["ERROR"]):
    if status in self.level_counts:
        status = "ERROR"

@@ +76,5 @@
> +            if error_level in self.level_counts:
> +                status = self._worst_status(status, MOZLOG_ERROR)
> +
> +        if style == 'TBPL':
> +            status = _tbpl_statuses[status]

This seems like very unfortunate coupling. Can't we just let the caller convert from whatever we return into values that it understands rather than hardcoding a specific set of values here?

Comment 3

[Chris Manchester (limited bugmail, email directly)]

(In reply to James Graham [:jgraham] from comment #2)
> Comment on attachment 8484976 [details] [diff] [review]
> Provide a mozlog handler to report overall status of a test run for the
> benefit of mozharness and others
> 
> Review of attachment 8484976 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: testing/mozbase/mozlog/mozlog/structured/handlers/statushandler.py
> @@ +4,5 @@
> > +
> > +from collections import defaultdict
> > +
> > +# TBPL statuses taken from mozharness' buildbot.py
> > +TBPL_SUCCESS = 'SUCCESS'
> 
> I really think the TBPL prefix here is something we should avoid if
> possible, expecially given that TBPL is on its way out. Can't we call it
> RUN_SUCCESS or something? I think I might also have a mild preference toward
> a named tuple rather than a long list of globals, but I could be convinced
> that I'm wrong there (my design would give an API like RUN_STATUS.SUCCESS)

Somewhere we need to translate a notion of a test run status provided by this handler into the actual string that will turn the tree a color (if not TBPL, then TREEHERDER). That doesn't have to be mozlog. I can conclude you don't think it should be.
> 
> @@ +12,5 @@
> > +TBPL_RETRY = 'RETRY'
> > +
> > +# Statuses provided by the mozlog's test results. This can probably be
> > +# extended for things like crashes.
> > +MOZLOG_OK = 'OK'
> 
> How valuable is it to make these constants rather than just well-known
> strings? If we think there is an advantage we should have a constants.py
> file in mozlog that exports all these symbols, again using a named tuple or
> dictionary or something.

Exporting the constants is probably more trouble than it's worth at the moment.

> 
> @@ +17,5 @@
> > +MOZLOG_TEST_FAIL = 'FAIL'
> > +MOZLOG_ERROR = 'ERROR'
> > +
> > +# Log levels that warrant an overall status of error for the run.
> > +_mozlog_error_levels = ('CRITICAL', 'ERROR')
> 
> I think this is unneeded, because you could just check level <=
> mozlog.structured.log_levels["ERROR"]

I find this confusing because mozlog's levels mean "lower is worse", while other loggers in the tree (python stdlib, Log.jsm, LogController.js) implement "higher is worse". Actually, can we change this?

> 
> @@ +35,5 @@
> > +        self.unexpected = 0
> > +        # A count of skip results (includes tests and subtests)
> > +        self.skipped = 0
> > +        # A count of top level tests run (test_end messages)
> > +        self.count = 0
> 
> Call this test_count?
> 
> In the interests of generality it might also be nice to make this a default
> dict keyed by status.

I'd like to just hand over a dict of status counts, but then my consumer doesn't have an idea of expected vs. unexpected.

> 
> @@ +66,5 @@
> > +        translation from mozlog statuses is provided."""
> > +        status = MOZLOG_OK
> > +
> > +        if self.count == 0:
> > +            status = self._worst_status(status, MOZLOG_ERROR)
> 
> this seems to just be status = MOZLOG_ERROR
> 
> @@ +69,5 @@
> > +        if self.count == 0:
> > +            status = self._worst_status(status, MOZLOG_ERROR)
> > +
> > +        if self.unexpected > 0:
> > +            status = self._worst_status(status, MOZLOG_TEST_FAIL)
> 
> It seems like if you moved this above anything that sets the status to ERROR
> we could just have
> 
> if self.unexpected:
>     status = "FAIL"
> 
> if not self.test_count:
>     status = "ERROR"
> 
> for error_level in (key for key,value in log_levels.iteritems() if value <=
> log_levels["ERROR"]):
>     if status in self.level_counts:
>         status = "ERROR"
> 
> @@ +76,5 @@
> > +            if error_level in self.level_counts:
> > +                status = self._worst_status(status, MOZLOG_ERROR)
> > +
> > +        if style == 'TBPL':
> > +            status = _tbpl_statuses[status]
> 
> This seems like very unfortunate coupling. Can't we just let the caller
> convert from whatever we return into values that it understands rather than
> hardcoding a specific set of values here?

Comment 4

[James Graham [:jgraham]]

(In reply to Chris Manchester [:chmanchester] from comment #3)
> (In reply to James Graham [:jgraham] from comment #2)
> > Comment on attachment 8484976 [details] [diff] [review]
> > Provide a mozlog handler to report overall status of a test run for the
> > benefit of mozharness and others
> > 
> > Review of attachment 8484976 [details] [diff] [review]:
> > -----------------------------------------------------------------
> > 
> > ::: testing/mozbase/mozlog/mozlog/structured/handlers/statushandler.py
> > @@ +4,5 @@
> > > +
> > > +from collections import defaultdict
> > > +
> > > +# TBPL statuses taken from mozharness' buildbot.py
> > > +TBPL_SUCCESS = 'SUCCESS'
> > 
> > I really think the TBPL prefix here is something we should avoid if
> > possible, expecially given that TBPL is on its way out. Can't we call it
> > RUN_SUCCESS or something? I think I might also have a mild preference toward
> > a named tuple rather than a long list of globals, but I could be convinced
> > that I'm wrong there (my design would give an API like RUN_STATUS.SUCCESS)
> 
> Somewhere we need to translate a notion of a test run status provided by
> this handler into the actual string that will turn the tree a color (if not
> TBPL, then TREEHERDER). That doesn't have to be mozlog. I can conclude you
> don't think it should be.

No, I think that leads to bad coupling where mozlog has to know about the details of some other system.

> > @@ +12,5 @@
> > > +TBPL_RETRY = 'RETRY'
> > > +
> > > +# Statuses provided by the mozlog's test results. This can probably be
> > > +# extended for things like crashes.
> > > +MOZLOG_OK = 'OK'
> > 
> > How valuable is it to make these constants rather than just well-known
> > strings? If we think there is an advantage we should have a constants.py
> > file in mozlog that exports all these symbols, again using a named tuple or
> > dictionary or something.
> 
> Exporting the constants is probably more trouble than it's worth at the
> moment.

Then can we just use the strings rather than global variables?

> > @@ +17,5 @@
> > > +MOZLOG_TEST_FAIL = 'FAIL'
> > > +MOZLOG_ERROR = 'ERROR'
> > > +
> > > +# Log levels that warrant an overall status of error for the run.
> > > +_mozlog_error_levels = ('CRITICAL', 'ERROR')
> > 
> > I think this is unneeded, because you could just check level <=
> > mozlog.structured.log_levels["ERROR"]
> 
> I find this confusing because mozlog's levels mean "lower is worse", while
> other loggers in the tree (python stdlib, Log.jsm, LogController.js)
> implement "higher is worse". Actually, can we change this?

Sure, if you can fix any consumers.

> > @@ +35,5 @@
> > > +        self.unexpected = 0
> > > +        # A count of skip results (includes tests and subtests)
> > > +        self.skipped = 0
> > > +        # A count of top level tests run (test_end messages)
> > > +        self.count = 0
> > 
> > Call this test_count?
> > 
> > In the interests of generality it might also be nice to make this a default
> > dict keyed by status.
> 
> I'd like to just hand over a dict of status counts, but then my consumer
> doesn't have an idea of expected vs. unexpected.

I don't think it makes sense to try and summarise to a different model than mozlog actually has here; where we control the consumer we can also change it to match the model where doing so makes sense.

Comment 5

[Chris Manchester (limited bugmail, email directly)]

(In reply to James Graham [:jgraham] from comment #4)
> (In reply to Chris Manchester [:chmanchester] from comment #3)
> > (In reply to James Graham [:jgraham] from comment #2)
> > > Comment on attachment 8484976 [details] [diff] [review]
> > > Provide a mozlog handler to report overall status of a test run for the
> > > benefit of mozharness and others
> > > 
> > > Review of attachment 8484976 [details] [diff] [review]:
> > > -----------------------------------------------------------------
> > > 
> > > ::: testing/mozbase/mozlog/mozlog/structured/handlers/statushandler.py
> > > @@ +4,5 @@
> > > > +
> > > > +from collections import defaultdict
> > > > +
> > > > +# TBPL statuses taken from mozharness' buildbot.py
> > > > +TBPL_SUCCESS = 'SUCCESS'
> > > 
> > > I really think the TBPL prefix here is something we should avoid if
> > > possible, expecially given that TBPL is on its way out. Can't we call it
> > > RUN_SUCCESS or something? I think I might also have a mild preference toward
> > > a named tuple rather than a long list of globals, but I could be convinced
> > > that I'm wrong there (my design would give an API like RUN_STATUS.SUCCESS)
> > 
> > Somewhere we need to translate a notion of a test run status provided by
> > this handler into the actual string that will turn the tree a color (if not
> > TBPL, then TREEHERDER). That doesn't have to be mozlog. I can conclude you
> > don't think it should be.
> 
> No, I think that leads to bad coupling where mozlog has to know about the
> details of some other system.
> 
> > > @@ +12,5 @@
> > > > +TBPL_RETRY = 'RETRY'
> > > > +
> > > > +# Statuses provided by the mozlog's test results. This can probably be
> > > > +# extended for things like crashes.
> > > > +MOZLOG_OK = 'OK'
> > > 
> > > How valuable is it to make these constants rather than just well-known
> > > strings? If we think there is an advantage we should have a constants.py
> > > file in mozlog that exports all these symbols, again using a named tuple or
> > > dictionary or something.
> > 
> > Exporting the constants is probably more trouble than it's worth at the
> > moment.
> 
> Then can we just use the strings rather than global variables?
> 
> > > @@ +17,5 @@
> > > > +MOZLOG_TEST_FAIL = 'FAIL'
> > > > +MOZLOG_ERROR = 'ERROR'
> > > > +
> > > > +# Log levels that warrant an overall status of error for the run.
> > > > +_mozlog_error_levels = ('CRITICAL', 'ERROR')
> > > 
> > > I think this is unneeded, because you could just check level <=
> > > mozlog.structured.log_levels["ERROR"]
> > 
> > I find this confusing because mozlog's levels mean "lower is worse", while
> > other loggers in the tree (python stdlib, Log.jsm, LogController.js)
> > implement "higher is worse". Actually, can we change this?
> 
> Sure, if you can fix any consumers.
> 
> > > @@ +35,5 @@
> > > > +        self.unexpected = 0
> > > > +        # A count of skip results (includes tests and subtests)
> > > > +        self.skipped = 0
> > > > +        # A count of top level tests run (test_end messages)
> > > > +        self.count = 0
> > > 
> > > Call this test_count?
> > > 
> > > In the interests of generality it might also be nice to make this a default
> > > dict keyed by status.
> > 
> > I'd like to just hand over a dict of status counts, but then my consumer
> > doesn't have an idea of expected vs. unexpected.
> 
> I don't think it makes sense to try and summarise to a different model than
> mozlog actually has here; where we control the consumer we can also change
> it to match the model where doing so makes sense.

Ok, but what exactly are you proposing? The alternative seem to be to enumerate ("unexpected_pass", "expected_fail"...) combinations. A single "unexpected" count seems to summarize what we need.

Comment 6

[Chris Manchester (limited bugmail, email directly)]

Attachment: Provide a mozlog handler to report overall status of a test run for the benefit of mozharness and others

Updated. I'll upload the mozharness changes here as well to give an idea of what this will look like in use.

Comment 7

[Chris Manchester (limited bugmail, email directly)]

Attachment: Modify mozharness' structurelog.py to use the mozlog status handler

The corresponding mozharness change.

Comment 8

[James Graham [:jgraham]]

Comment on attachment 8488702 [details] [diff] [review]
Provide a mozlog handler to report overall status of a test run for the benefit of mozharness and others

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

Just a few fixups to address.

::: testing/mozbase/mozlog/mozlog/structured/handlers/statushandler.py
@@ +15,5 @@
> +        # A count of skip results (includes tests and subtests)
> +        self.skipped = 0
> +        # A count of top level tests run (test_end messages)
> +        self.test_count = 0
> +        self.level_counts = defaultdict(int)

Give this a comment for consistency.

@@ +25,5 @@
> +            self.level_counts[data['level']] += 1
> +        elif action == 'test_end':
> +            self.test_count += 1
> +
> +        if 'expected' in data:

I guess these should be inside 'if action in ("test_status", "test_end")'

Comment 9

[Chris Manchester (limited bugmail, email directly)]

Attachment: Provide a mozlog handler to report overall status of a test run for the benefit of mozharness and others

Updated and a little bit of try:
https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=9ca2136f45c1

Comment 10

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/05e0ca243abf

Comment 11

[Carsten Book [:Tomcat]]

https://hg.mozilla.org/mozilla-central/rev/05e0ca243abf