Merge lp:~jameinel/bzr/2.3-filter-tests into lp:bzr

so for skip I think keeping the log is important, it may well have
hints to why something gets skipped beyond the reason; for xfail this
makes sense to me.

Looking at the implementation, I'd rather see discardDetail in
testtools upstream - no need to do it in bzr at all.

But, I don't think its correct, you say that the log becomes part of
the reason, but that doesn't make sense at all.

Whats the size issue with PQM? We don't skip all that many tests...

-Rob

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 8/29/2010 3:34 AM, Robert Collins wrote:
> so for skip I think keeping the log is important, it may well have
> hints to why something gets skipped beyond the reason; for xfail this
> makes sense to me.
>
> Looking at the implementation, I'd rather see discardDetail in
> testtools upstream - no need to do it in bzr at all.
>
> But, I don't think its correct, you say that the log becomes part of
> the reason, but that doesn't make sense at all.
>
> Whats the size issue with PQM? We don't skip all that many tests...
>
> -Rob

We skip 2200 tests, and it causes the log file to become 7.2MB in size.
I would consider that both "many tests" and a "large output".

John
=:->
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkx6YGsACgkQJdeBCYSNAAPqZwCZAUQod44FAGp2akiiR5mS+5mV
4SkAn0SKZCP/szWfI8gXQbyLE8mWk4p9
=lx8l
-----END PGP SIGNATURE-----

> It also should reduce some of the noise when running selftest -v. It doesn't
> change addSkip to report the 'reason' as a single line like we used to,
> though I would consider working on that if people would like it. (basically,
> if the details dict only contains reason, just display it, rather that doing
> the full formatting dance.)

The added noise is a straight-up regression from the switch to the testtools api, which I finally got round to filing as bug 625597 a couple of days back. That wants fixing regardless of whether we want to selectively clear logs like this, and mostly means submitting to an ever more testtools oriented style.

I'm not certain that clearing logs is the right thing. Generally I'd think it a bug if skipped tests have long log files. Some tests take a second to run, leak a thread, and just skip anyway.

Overall I think I'd prefer this happened in subunit. Passing tests also have logs, but I'm guessing subunit doesn't show their details at all.

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 8/29/2010 3:34 AM, Robert Collins wrote:
> so for skip I think keeping the log is important, it may well have
> hints to why something gets skipped beyond the reason; for xfail this
> makes sense to me.
>
> Looking at the implementation, I'd rather see discardDetail in
> testtools upstream - no need to do it in bzr at all.
>
> But, I don't think its correct, you say that the log becomes part of
> the reason, but that doesn't make sense at all.

            try:
                return addSkip(test, details=details)
            except TypeError:
                # have to convert
                reason = _details_to_str(details)

John
=:->
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkx6nNUACgkQJdeBCYSNAAP+aACg1hSD+eXY7BtAHVZkNSgz4sOp
dosAnjvRBFQ8zZ4FNiVwVSMq3HQIk8Cf
=FHMt
-----END PGP SIGNATURE-----

So, 2200 tests is 10% of the total, the other 90% still gather all the logs.

That try:finally: demonstrates that bzr *just needs to update its API*
- its going via the compatibility code path.

As a data point, I still can't get any email from PQM on failures.

I just had to reproduce a problem and the raw selftest.log containing the uncompressed,
unfiltered, selftest.log is 47M.

I'm not quite sure about which stream is sent on failure but I suspect it is this one.

So, for debugging purposes, I don't like removing stuff.
But I currently get *nothing* so can we step back a bit and addresses this
problem once and for all ?

Should we send a very short mail on failures with an url to get the whole stream for example ?

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 8/29/2010 2:58 PM, Robert Collins wrote:
> So, 2200 tests is 10% of the total, the other 90% still gather all the logs.
>
> That try:finally: demonstrates that bzr *just needs to update its API*
> - its going via the compatibility code path.

except doesn't subunit as well...

But you bring up a good point. I didn't realize that success was also
generating log output, which I would also like to suppress.

It is still 7MB as an email, which means that we are failing to get
failure emails sometimes.

John
=:->
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkx71LgACgkQJdeBCYSNAAPeMACgvRlxuJqN+rktJhYl4OhAdRou
fVAAoIO8aM4md+G5J6BkM7BzML9Iapry
=BX5H
-----END PGP SIGNATURE-----

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

On 8/30/2010 9:53 AM, Vincent Ladeuil wrote:
> As a data point, I still can't get any email from PQM on failures.
>
> I just had to reproduce a problem and the raw selftest.log containing the uncompressed,
> unfiltered, selftest.log is 47M.
>
> I'm not quite sure about which stream is sent on failure but I suspect it is this one.
>
> So, for debugging purposes, I don't like removing stuff.
> But I currently get *nothing* so can we step back a bit and addresses this
> problem once and for all ?
>
> Should we send a very short mail on failures with an url to get the whole stream for example ?

Do you really feel that including the log output for xfail, skip, and
success is adding useful info? *I* feel it is just adding a lot of noise
with almost 0 signal...

I guess we've reached the point of
a) Bringing it to the main list.
b) Intelligent people disagreeing, so we need a vote/proclamation to
resolve.

John
=:->
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkx71QQACgkQJdeBCYSNAAN00ACgg+SJtQXxn82gzddD4lwbC7oR
bhwAoMQCynk7MyVt/YTocoGwePfBVxAz
=aQpv
-----END PGP SIGNATURE-----

>>>>> John Arbash Meinel <email address hidden> writes:

    > On 8/30/2010 9:53 AM, Vincent Ladeuil wrote:
    >> As a data point, I still can't get any email from PQM on failures.
    >>
    >> I just had to reproduce a problem and the raw selftest.log containing the uncompressed,
    >> unfiltered, selftest.log is 47M.
    >>
    >> I'm not quite sure about which stream is sent on failure but I suspect it is this one.
    >>
    >> So, for debugging purposes, I don't like removing stuff.
    >> But I currently get *nothing* so can we step back a bit and addresses this
    >> problem once and for all ?
    >>
    >> Should we send a very short mail on failures with an url to get the whole stream for example ?

    > Do you really feel that including the log output for xfail, skip, and
    > success is adding useful info?

No. But you forgot 'not applicable' :-P

    > *I* feel it is just adding a lot of noise with almost 0 signal...

Right, so ISTM that we agree about two things:

- we want the list of tests and their status (pass/fail/skip etc.)
- we care about log only for failures.

Don't we get that by simply *not* using subunit on pqm ?

Or is pqm.bazaar-cvs.org *requiring* subunit ?

we did two simultaneous things a while back:
 - turned off -1, so that we get *all* failures
 - turned on subunit, so that the failures are machine driven

The emails are meant to be compressed, so you should in principle be
able get it reliably.

If we're actually running into mailer limits, we can do a few things:
 - turn off subunit (will reduce some of the overhead - lots in a
success case, but in a it-all-goes-pear-shaped failure, you'll still
hit the limit and whatever undiagnosed and unfixed issue is biting you
now, will bite you then.
 - diagnose and fix the mailer path issue so that you receive the mails reliably
 - stop using email to send the results
 - filter the stream at source so success and other results that you
consider uninteresting are not included in the 'raw' stream. Note that
again, this will *leave the failure mode in place so when it goes bad
you will stop getting the responses*

Now, I'm not directly experiencing this anymore, so you need to do
what makes sense to you.

If subunit's API is out of date and messing up the reason formatting,
I'll happily fix it - I'm going to go peek and see if its addSkip is
stale right after mailing this.

To stop using email to send the results, we either need to design a
new thing and change PQM to do it, or reenable the LP API support,
which Tim requested we disable.

We previously *haven't* filtered at source as a defensive measure
against bugs. Python 2 is riddled with default-encoding pitfalls and
they made subunit + bzr very unreliable at one point. Possibly totally
fixed thanks to Martin[gz].

Personally, I would not take any action that leaves the problem fallow
waiting for a serious test failure to provoke it: that just means that
when you need it most it will fail. However, as I say above: you're
using this system, I'm rarely using it : do what makes sense to you. I
do strongly suggest that you change things in PQM itself if you want
filtering, rather than bzr. That will at least preserve the detailed
output for babune if you do need it in future.

As for the value of logs on success, xfail, skip etc : *if* they pass
incorrectly, I think the log will be invaluable, but you won't need it
till you need it.

-Rob

>>>>> Robert Collins <email address hidden> writes:

    > we did two simultaneous things a while back:
    > - turned off -1, so that we get *all* failures

+1

    > - turned on subunit, so that the failures are machine driven

ECANTPARSE

    > The emails are meant to be compressed, so you should in principle
    > be able get it reliably.

In practice I only get failures for merge errors, any error in the test
suite and... it's not delivered.

    > If we're actually running into mailer limits, we can do a few
    > things:

    > - turn off subunit (will reduce some of the overhead - lots in a
    > success case, but in a it-all-goes-pear-shaped failure, you'll
    > still hit the limit and whatever undiagnosed and unfixed issue is
    > biting you now, will bite you then.

Yup, exactly my feeling.

    > - diagnose and fix the mailer path issue so that you receive the
    > mails reliably

As a data point, John got an email for a failure and *I* didn't get it
for the same failure (or so very closely the same failure that the
difference doesn't matter).

This means the problem is on my side but I don't know where exactly. I
use fetchmail and there is *nothing* in the logs so that also rules out
the delivery part. That leaves my ISP mail server... and I don't control
it. That's me, but it could apply to anybody else, we just don't know.

    > - stop using email to send the results

Or store the results somewhere (deleting them after a day/week/month
whatever).

Or send two mails:
- one indicating the failure
- one with the stream attached.

At least with that I will *know* there was a failure.

    > - filter the stream at source so success and other results that
    > you consider uninteresting are not included in the 'raw'
    > stream. Note that again, this will *leave the failure mode in
    > place so when it goes bad you will stop getting the responses*

Another idea would be to have a different pqm instance used only for
known failures and make the output for the regular pqm includes only
*failures* and get rid of *all* the rest.

    > Now, I'm not directly experiencing this anymore, so you need to do
    > what makes sense to you.

Thanks for your thoughts anyway.

    > If subunit's API is out of date and messing up the reason
    > formatting, I'll happily fix it - I'm going to go peek and see if
    > its addSkip is stale right after mailing this.

Cool, any feedback ?

    > To stop using email to send the results, we either need to design
    > a new thing and change PQM to do it, or reenable the LP API
    > support, which Tim requested we disable.

And what would that give us ? Failed run stream attached to the mp as an
attachment ?

    > We previously *haven't* filtered at source as a defensive measure
    > against bugs. Python 2 is riddled with default-encoding pitfalls
    > and they made subunit + bzr very unreliable at one point. Possibly
    > totally fixed thanks to Martin[gz].

I still expect a few (tiny but annoying) bugs to be fixed there...

    > Personally, I would not take any action that leaves the problem
    > fallow waiting for a serious test failure to provoke it: that just
    > means tha...

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

...

> > - turn off subunit (will reduce some of the overhead - lots in a
> > success case, but in a it-all-goes-pear-shaped failure, you'll
> > still hit the limit and whatever undiagnosed and unfixed issue is
> > biting you now, will bite you then.
>
> Yup, exactly my feeling.
>
> > - diagnose and fix the mailer path issue so that you receive the
> > mails reliably
>
> As a data point, John got an email for a failure and *I* didn't get it
> for the same failure (or so very closely the same failure that the
> difference doesn't matter).

Right. For that 'failure' there was a single test failing. And the size
of the compressed log is 3.2MB, which makes it about 7MB according to
Thunderbird. (Figure base64 encoding, and ?).

It is true that if you have a huge 'everything fails' case, you'll still
get into that range. Though I did have one of those recently that broke
the 10MB barrier and caused the mail to fail to reach me. Which was,
indeed, much harder for me to track down and fix.

However, getting rid of 7MB (of compressed+base64) success content would
get a lot more headroom for when a few tests fail (or even a few hundred
fail).

...

> > To stop using email to send the results, we either need to design
> > a new thing and change PQM to do it, or reenable the LP API
> > support, which Tim requested we disable.
>
> And what would that give us ? Failed run stream attached to the mp as an
> attachment ?

I don't think you can attach stuff to an MP. I think it would actually
try to set it as a message...

John
=:->
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (Cygwin)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org/

iEYEARECAAYFAkx9JG0ACgkQJdeBCYSNAAMWcQCgrPHen1zB4dpr7AR1vJToTKxc
3BwAnR8AFECkruco07VCTPhTpFYFu8Xt
=jceX
-----END PGP SIGNATURE-----

This is now a couple of weeks old and I'd like to wrap it up.

I think it would be reasonable to merge it, and at least see what we think about it. I cannot recall looking at the logs attached to an xfail, skip or notapplicable test for a long time. The normal and common thing is that they'll have a fairly selfexplanatory message about being either known broken, or skipped because of a missing dependency, or whatever. In the source, the code that raises that exception is normally pretty obvious. If the test is being wrongly skipped, then the logs probably won't help and you need to dig in with pdb or something.

There is some unhelpful data logged by bzr and we could push down on that too.

On the whole I'm ok to merge this; it seems like it's just a couple of lines to turn it back on if we need to.

If this is going to land, there are some things that should really be fixed first.

+ self._suppress_log ()

No space.

+ def _report_skip(self, result, e):

Rather than adding this, put the call in _do_skip instead?

ExtendedTestResult.addSuccess appears to have a similar hack spelt in a different way:

        test._log_contents = ''

Remove that and add your new version instead?

Would really like some kind of test.

On 22/09/2010, John Arbash Meinel <email address hidden> wrote:
>>
>> + def _report_skip(self, result, e):
>>
>> Rather than adding this, put the call in _do_skip instead?
>
> IIRC, there was a reason to put it in _report_skip. I don't remember
> exactly, but I think it was that _report_skip gets called for all code
> paths, but _do_skip doesn't. (NotAvailable, vs Skip, vs XFAIL?)

I think this is true for fallbacks, but we shouldn't be using any? If
it does need doing this way explaining why in the docstring would be
good.

>> ExtendedTestResult.addSuccess appears to have a similar hack spelt in a
>> different way:
>>
>> test._log_contents = ''
>>
>> Remove that and add your new version instead?
>
> Given that that one doesn't actually seem to work, I guess that would be
> reasonable.

Removing the log from successes would be the biggest win as you've noted.

>> Would really like some kind of test.
>
> I think I can work something out in test_selftest, about what details
> are present in the final result. I'll give it a poke and see what I get.
>
> I'd certainly also like to suppress the log details for success cases.
>
> John
> =:->

Please re-review. I've:

a) Added tests about details, etc, when running locally
b) Added tests for what is contained in the subunit stream
c) Hopefully updated the docs sufficiently for Martin [gz].

Let's land this. The tests are worth having even when the bzrlib ExtendedTestResult class is fixed to print less junk on the console or subunit starts being pickier about what it does with success results.

A couple of notes. Thanks for the reasoning for _report_skip, makes it clear the method can probably be removed when the bzrlib/testtools boundary starts treating exceptions properly. The new tests that use testtools.TestResult rather than ExtendedTestResult check some things that would fail if the class switched because the behaviours are still quite different in a number of areas, but they should probably be converging anyway.

I did a quick test run with an artificially failing test, and I saw that it did help, a lot. 7.3MB down to 1.3MB for the email. (Email size, not size of .gz not uncompressed size)

sent to pqm by email