libglib-perl version 2:1.241-1 FTBFS on i386 in precise

[Andreas Moog]

This is a semi-automatic report based on the latest archive rebuild results [1].
Apologies if it reaches you in error.

Excerpt from the buildlog:

Manifying blib/man3/Glib::Markup.3pm
Manifying blib/man3/Glib::KeyFile.3pm
make[1]: Leaving directory `/build/buildd/libglib-perl-1.241'
   dh_auto_test
make[1]: Entering directory `/build/buildd/libglib-perl-1.241'
PERL_DL_NONLAZY=1 /usr/bin/perl "-MExtUtils::Command::MM" "-e" "test_harness(0, 'blib/lib', 'blib/arch')" t/*.t
t/1.t ...................... ok
t/2.t ...................... ok
t/3.t ...................... ok
t/4.t ...................... ok
t/5.t ...................... ok
t/6.t ...................... ok
t/64bit.t .................. ok
t/7.t ...................... ok
t/8.t ...................... ok
*** unhandled exception in callback:
*** Oops, child watch callback didn't run
*** ignoring at t/9.t line 267.

Session terminated, terminating shell...make: *** [build] Terminated
make[1]: *** [test_dynamic] Terminated
 ...terminated.
Build killed with signal 15 after 180 minutes of inactivity
******************************************************************************
Build finished at 20120202-1415
FAILED [dpkg-buildpackage died]

The full buidlog can be found at https://launchpad.net/ubuntu/+archive/test-rebuild-20120201/+build/3156403/+files/buildlog_ubuntu-precise-i386.libglib-perl_2:1.241-1_FAILEDTOBUILD.txt.gz.

[1] http://people.ubuntuwire.org/~wgrant/rebuild-ftbfs-test/test-rebuild-20120201-precise.html

[gregor herrmann (gregoa)]

On Wed, 22 Feb 2012 09:17:15 -0000, Matthias Klose wrote:

> ** Also affects: libglib-perl (Ubuntu Precise)
> Importance: High
> Status: Confirmed
>
> ** Changed in: libglib-perl (Ubuntu Precise)
> Milestone: None => ubuntu-12.04-beta-1

I've now built 2:1.241-1 (from snapshot.d.o) and 2:1.242-1 (from
Debian/unstable) in a precise i386 cowbuilder chroot.

Both build without any problem. - No idea, what was different on the
automatic precise rebuild ...

(Not very helpful, I know. Anyway, if we can do anything on the
Debian side just shout.)

Cheers,
gregor, Debian Perl Group

--
 .''`. Homepage: http://info.comodo.priv.at/ - OpenPGP key 0xBB3A68018649AA06
 : :' : Debian GNU/Linux user, admin, and developer - http://www.debian.org/
 `. `' Member of VIBE!AT & SPI, fellow of the Free Software Foundation Europe
   `- NP: Dire Straits: Solid Rock

[Allison Randal (allison)]

This is a heisenbug because it's a simple race condition. It's not a failure in the package build, only in the automated tests. The lines just before 267 of the test file t/9.t are:

264 $timer_id = Glib::Timeout->add
265 (30_000, # 30 seconds should be more than enough for child exit
266 sub { die "Oops, child watch callback didn't run\n"; });

The test is assuming that 30 seconds are long enough for a child process to complete, but on certain slower/constrained processors (like a buildd, or a netbook) that estimate is too short, so the test fails. On my Precise netbook (Asus EeePC N550 @ 1.50GHz × 4) the test consistently fails, but if I bump that timeout up to 60 seconds it consistently passes. That timing is not exact, and an ideal fix would be event-based rather than wallclock seconds, but doubling the time allowed is generous. Alternatively, you can ignore the FTBFS, since it's only a sign of a slow buildd, not of any more serious problem.

I've attached the patch file I added in my bzr checkout of the package for a longer timeout.

[Ubuntu Foundations Team Bug Bot (crichton)]

The attachment "lengthen the timeout, so the test passes for slower processors" of this bug report has been identified as being a patch. The ubuntu-reviewers team has been subscribed to the bug report so that they can review the patch. In the event that this is in fact not a patch you can resolve this situation by removing the tag 'patch' from the bug report and editing the attachment so that it is not flagged as a patch. Additionally, if you are member of the ubuntu-reviewers team please also unsubscribe the team from this bug report.

[This is an automated message performed by a Launchpad user owned by Brian Murray. Please contact him regarding any issues with the action taken in this bug report.]

[Sebastien Bacher (seb128)]

Thanks for your work Allison, could you send that patch back to Debian? libglib-perl is on sync between Debian and Ubuntu at the moment and that diff doesn't seem worth changing that, also I'm unsure if that patch is worth a SRU upload since that's only a slow machine issue and normal users will not need to rebuild the package but use the binaries from the archive which are built

[David Benjamin (davidben)]

The child process is literally doing nothing but calling POSIX::_exit. I find it hard to believe that the problem is that a slow machine takes more than 30 seconds to process that. I think it's more likely there's another problem here.

  my $pid = fork();
  if (! defined $pid) {
    die "oops, cannot fork: $!";
  }
  if ($pid == 0) {
    # child
    require POSIX;
    POSIX::_exit(42); # no END etc cleanups
  }

[David Benjamin (davidben)]

> That timing is not exact, and an ideal fix would be event-based rather than wallclock seconds, but doubling the time allowed is generous.

It's also worth noting that the test is testing something event-based in the first place. It's testing that child watches fire events when the child dies. The timeout is only there if it fails and hangs. So this doesn't mean the test is flakey and uses ad-hoc timeouts. It means the test is failing.