test suite: FIXED messages are misordered with tests

test suite: FIXED messages are misordered with tests

[Daniel Kahn Gillmor]

[-- Attachment #1.1: Type: text/plain, Size: 1402 bytes --]

I'm debugging/diagnosing/trying to clean up some "FIXED" known-broken
tests right now.

Sometimes, depending on circumstances i can't predict (race
conditions?), I see funny output like:

~~~
Use "make V=1" to see the details for passing and known broken tests.
INFO: using 2m timeout for tests
INFO: running tests with moreutils parallel
 FIXED  verify signed PKCS#7 subject (onepart-signed) signer User ID

T356-protected-headers: Testing Message decryption with protected headers
 BROKEN confirm signed and encrypted PKCS#7 subject (sign+enc)
 BROKEN confirm signed and encrypted PKCS#7 subject (sign+enc) signer User ID
 BROKEN confirm signed and encrypted PKCS#7 subject (sign+enc+legacy-disp)
 BROKEN confirm signed and encrypted PKCS#7 subject (sign+enc+legacy-disp) signer User ID
 BROKEN confirm encryption-protected PKCS#7 subject (enc+legacy-disp)
~~~


Clearly, that FIXED should come *after* the "T356-protected-headers:"
separator.

This is a minor bug, i suppose, but i confess i don't understand the
maze of shell functions in test-lib.sh well enough to see why this is
happening, let alone to fix it.

Anyone interested in fixing it should be able to do so by marking a good
test "known broken" and then re-running the test suite.  The above
output is taken from:

    make -j4 check NOTMUCH_TESTS=T356-protected-headers.sh

Sorry to send a bug report with no fixes!

           --dkg

[-- Attachment #1.2: signature.asc --]
[-- Type: application/pgp-signature, Size: 227 bytes --]

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: test suite: FIXED messages are misordered with tests

[David Bremner]

Daniel Kahn Gillmor <dkg@fifthhorseman.net> writes:
>
> Clearly, that FIXED should come *after* the "T356-protected-headers:"
> separator.
>

Can you reproduce this without running the tests in parallel?

d

Re: test suite: FIXED messages are misordered with tests

[Daniel Kahn Gillmor]

[-- Attachment #1.1: Type: text/plain, Size: 747 bytes --]

On Tue 2020-05-12 20:14:07 -0300, David Bremner wrote:
> Daniel Kahn Gillmor <dkg@fifthhorseman.net> writes:
>>
>> Clearly, that FIXED should come *after* the "T356-protected-headers:"
>> separator.
>>
>
> Can you reproduce this without running the tests in parallel?

Yep:

I've seen the misordered output when using "make -j4 check".

I've also seen it with plain old "make check".

And i can replicate it with:

    make check NOTMUCH_TEST_SERIALIZE=1 NOTMUCH_TESTS=T355-smime.sh

(i don't think NOTMUCH_TEST_SERIALIZE=1 makes any difference when only
one item is present in NOTMUCH_TESTS)

I also tried "make check NOTMUCH_TEST_SERIALIZE=1" (so slow, i'm spoiled
by the parallel test suite!) and yes, i see the same problem there.

     --dkg

[-- Attachment #1.2: signature.asc --]
[-- Type: application/pgp-signature, Size: 227 bytes --]

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: test suite: FIXED messages are misordered with tests

[Tomi Ollila]

On Tue, May 12 2020, Daniel Kahn Gillmor wrote:

> I'm debugging/diagnosing/trying to clean up some "FIXED" known-broken
> tests right now.
>
> Sometimes, depending on circumstances i can't predict (race
> conditions?), I see funny output like:
>
> ~~~
> Use "make V=1" to see the details for passing and known broken tests.
> INFO: using 2m timeout for tests
> INFO: running tests with moreutils parallel
>  FIXED  verify signed PKCS#7 subject (onepart-signed) signer User ID
>
> T356-protected-headers: Testing Message decryption with protected headers
>  BROKEN confirm signed and encrypted PKCS#7 subject (sign+enc)
>  BROKEN confirm signed and encrypted PKCS#7 subject (sign+enc) signer User ID
>  BROKEN confirm signed and encrypted PKCS#7 subject (sign+enc+legacy-disp)
>  BROKEN confirm signed and encrypted PKCS#7 subject (sign+enc+legacy-disp) signer User ID
>  BROKEN confirm encryption-protected PKCS#7 subject (enc+legacy-disp)
> ~~~
>
> Clearly, that FIXED should come *after* the "T356-protected-headers:"
> separator.


After your second mail I tried to reproduce by taking a test file,
marking one known_broken, even it is not to get FIXED, and then broke
next one.

And I got it reproduced.

the message that prints FIXED, does not execute print_test_description
but the ones that do BROKEN or FAIL does (did not fully check but yes).

And:

    print_test_description ()
    {
        test -z "$test_description_printed" || return 0
        echo
        echo $this_test: "Testing ${test_description}"
        test_description_printed=1
    }
    if [ -z "$NOTMUCH_TEST_QUIET" ]
    then
        print_test_description
    fi


Tomi


>
> This is a minor bug, i suppose, but i confess i don't understand the
> maze of shell functions in test-lib.sh well enough to see why this is
> happening, let alone to fix it.
>
> Anyone interested in fixing it should be able to do so by marking a good
> test "known broken" and then re-running the test suite.  The above
> output is taken from:
>
>     make -j4 check NOTMUCH_TESTS=T356-protected-headers.sh
>
> Sorry to send a bug report with no fixes!
>
>            --dkg
> _______________________________________________
> notmuch mailing list
> notmuch@notmuchmail.org
> https://notmuchmail.org/mailman/listinfo/notmuch

Re: test suite: FIXED messages are misordered with tests

[Tomi Ollila]

On Thu, May 21 2020, Tomi Ollila wrote:

>
> the message that prints FIXED, does not execute print_test_description
> but the ones that do BROKEN or FAIL does (did not fully check but yes).
>
> And:
>
>     print_test_description ()
>     {
>         test -z "$test_description_printed" || return 0
>         echo
>         echo $this_test: "Testing ${test_description}"
>         test_description_printed=1
>     }


btw: I would rewrite this function as:

     print_test_description ()
     {
         echo
         echo $this_test: "Testing ${test_description}"

         print_test_description () { :; }         
     }

If I wanted to reduce XTRACE noise (even further), even further:

     _print_test_description ()
     {
         echo
         echo $this_test: "Testing ${test_description}"

         print_test_description=
     }
     print_test_description=_print_test_description

(and then use $print_test_description in "calls")

or even

     alias print_test_description='
       echo
       echo echo $this_test: "Testing ${test_description}"
       alias print_test_description='

(just tested this latest works)

Note on aliases: bash namual states:

 For almost every purpose, aliases are superseded by shell functions.

One notable exception is XTRACE noise reduction. In our case best 
candidate would be prerequisite work -- but SMOP..

Tomi

>     if [ -z "$NOTMUCH_TEST_QUIET" ]
>     then
>         print_test_description
>     fi
>
> Tomi

Re: test suite: FIXED messages are misordered with tests

[Daniel Kahn Gillmor]

[-- Attachment #1.1: Type: text/plain, Size: 167 bytes --]

On Thu 2020-05-21 00:16:48 +0300, Tomi Ollila wrote:
> (just tested this latest works)

Thanks for looking into this, Tomi!

Do you have a patch to propose?

   --dkg

[-- Attachment #1.2: signature.asc --]
[-- Type: application/pgp-signature, Size: 227 bytes --]

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]

Re: test suite: FIXED messages are misordered with tests

[Tomi Ollila]

On Thu, May 21 2020, Daniel Kahn Gillmor wrote:

> On Thu 2020-05-21 00:16:48 +0300, Tomi Ollila wrote:
>> (just tested this latest works)
>
> Thanks for looking into this, Tomi!
>
> Do you have a patch to propose?

Looked a bit (now). Somewhat complicated to make perfect (enemy of good)
change.

print_test_description could be added as first line in 
test_known_broken_ok_ (then inconsistent with test_known_broken_failure_)
or in test_ok_ just before calling test_known_broken_ok_ 
(test_known_broken_ok_ is called only once in test-lib.sh)

but it looks like test_check_missing_external_prereqs_ and
test_report_skip_ may be called before print_test_description is called
(and there may be more...)

We've accumulated quite a bit of mess during these years to the test
system, which makes it harder to do larger adjustments (and not (yet)
mentioning even larger refactorings...).

>
>    --dkg

Tomi

Re: test suite: FIXED messages are misordered with tests

[Daniel Kahn Gillmor]

[-- Attachment #1.1: Type: text/plain, Size: 679 bytes --]

On Fri 2020-05-22 00:57:14 +0300, Tomi Ollila wrote:
> We've accumulated quite a bit of mess during these years to the test
> system, which makes it harder to do larger adjustments (and not (yet)
> mentioning even larger refactorings...).

The last significant refactoring was probably when jrollins and i got
the test suite running in parallel, and that might not even qualify as
"major".  Of course, the most effective tool for encouraging any
refactoring is having a robust and reliable test suite to make sure that
nothing broke.  But now we're talking about a test suite for the test
suite…  i dunno how far we want to go down the rabbit hole!

        --dkg

[-- Attachment #1.2: signature.asc --]
[-- Type: application/pgp-signature, Size: 227 bytes --]

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]