Re: Perl package failing to migrate to testing

[Russ Allbery <rra@debian.org>]

Jeff <jffry@posteo.net> writes:

> I have Perl package (not team-maintained, as it is an application, not a
> library), which is failing to migrate to testing because of test
> failures with riscv64:

> https://tracker.debian.org/pkg/gscan2pdf

> How can I go about debugging this? I don't have a riscv64 machine to hand.

> gscan2pdf is a desktop application. Are there even riscv64 desktop
> users?  Would it be valid to simply skip tests for riscv64?

The concrete answer to your question is that Debian has porterboxes
available for various architectures including this one.  DDs should
already have access; Debian maintainers who are not DDs can request guest
access.  See https://wiki.debian.org/PorterBoxHowToUse.

For the problem itself, this looks suspiciously like a race condition to
me, although I'm not sure why it would fail only on riscv64.  The test
code that's failing is the following in 1111_save_pdf.t:

# use a new main loop to avoid nesting, which was preventing the counters
# resetting in some environments
my $loop = Glib::MainLoop->new;
my $flag = FALSE;
$slist->import_files(
    paths            => ['test.pnm'],
    started_callback => sub {
        my ( $thread, $process, $completed, $total ) = @_;
        is( $completed, 0, 'completed counter starts at 0' );
        is( $total,     2, 'total counter starts at 2' );
    },
    finished_callback => sub {
        is( $slist->scans_saved, '', 'pages not tagged as saved' );
        $flag = TRUE;
        $loop->quit;
    }
);
$loop->run unless ($flag);

What's happening here is that the started_callback is running twice:

1103s ok 1 - use Gscan2pdf::Document;
1103s ok 2 - completed counter starts at 0
1103s not ok 3 - total counter starts at 2
1103s 
1103s #   Failed test 'total counter starts at 2'
1103s #   at t/1111_save_pdf.t line 39.
1103s #          got: '1'
1103s #     expected: '2'
1103s ok 4 - completed counter starts at 0
1103s ok 5 - total counter starts at 2

Notice how there are two completed and total counter test outputs, and
then at the end of the test it says:

1103s # Looks like you planned 9 tests but ran 11.
1103s # Looks like you failed 1 test of 11 run.
1103s Dubious, test returned 1 (wstat 256, 0x100)

which implies to me that the started_callback is only supposed to run
once.

I have absolutely zero experience with the Perl Glib integration, but just
eyeballing this code, it looks like the finished_callback is supposed to
set $flag to false so that $loop->run doesn't run (a second time? there
seems to be some threading or other implicit parallelization going on
here).

So my hypothesis, which is a straight-up guess that may be wrong since I
don't know how these libraries work, is that for some reason on this
platform this code gets run twice, presumably because the
finished_callback hasn't run before it reaches the $loop->run line, and
that's also causing some sort of race that causes the total counter to be
1 instead of 2.

If it is a race condition, this may be a general problem with the test
that could trigger elsewhere, but just happened to trigger on this
architecture for some reason.  But it's also quite possible that glib
works subtly differently on this platform for some reason.

-- 
Russ Allbery (rra@debian.org)              <https://www.eyrie.org/~eagle/>