Bug#841662: libserver-starter-perl: test suite sometimes times out

[gregor herrmann]

On Fri, 21 Oct 2016 23:13:53 +0300, Niko Tyni wrote:

> This package occasionally fails its autopkgtest checks on ci.debian.net.
> 
>   https://ci.debian.net/packages/libs/libserver-starter-perl/unstable/amd64/
> 
> It's not clear to me which test is hanging; it looks like t/04-starter-dir.t
> finishes properly but I guess it could also be its cleanup or something.

0) As expected, I can't reproduce the failures in t/04-starter-dir.t.

1) The output of t/04-starter-dir.t looks the same in the failure
   cases from ci.d.n and my local success cases:

t/04-starter-dir.t .....
1..1
start_server (pid:9868) starting now...
starting new worker 9869
worker 9869 died unexpectedly with status:0, restarting
ok 1
starting new worker 9870
received TERM, sending TERM to all workers:9870
worker 9870 died, status:15
exiting
ok

t/04-starter-dir.t ..
1..1
start_server (pid:17269) starting now...
starting new worker 17270
worker 17270 died unexpectedly with status:0, restarting
ok 1
starting new worker 17297
received TERM, sending TERM to all workers:17297
worker 17297 died, status:15
exiting
ok

2) There's one issue + pull request which look at least potentially
   related:
   https://github.com/kazuho/p5-Server-Starter/issues/44
   https://github.com/kazuho/p5-Server-Starter/pull/45

  Or not, as I don't see either $ENV{KILL_OLD_DELAY} or
  $ENV{ENABLE_AUTO_RESTART} anywhere in the tests.
   
3) Looking into t/04-starter-dir.t I see lots of pipes, forks,
   sleeps, signals, kills, waits, ... which all smells like a good
   place for failure, but I don't understand the code sufficiently to
   be able to point to one line.

4) Oh, and while writing this mail, I got t/05-killolddelay.t to hang:

t/05-killolddelay.t .. 
1..28
start_server (pid:31565) starting now...
starting new worker 31566
ok 1 - connect
ok 2 - write
ok 3 - read
ok 4 - read
ok 5 - status before restart
received HUP, spawning a new worker
starting new worker 31605
new worker is now running, sending TERM to old workers:31566
sleeping 3 secs before killing old workers
ok 6 - status during restart
killing old workers
old worker 31566 died, status:0
ok 7 - status after restart
ok 8 - signal sent on hup
ok 9 - reconnect
ok 10 - write after switching
ok 11 - read after switching
ok 12 - read after swiching (format)
ok 13 - pid should have changed
received TERM, sending TERM to all workers:31605
worker 31605 died, status:0
exiting
[Test::TCP] Child process does not block(PID: 31565, PPID: 31564) at /usr/share/perl5/Test/TCP.pm line 103.
ok 14 - no more status file
start_server (pid:31717) starting now...
starting new worker 31718
ok 15 - connect
ok 16 - write
ok 17 - read
ok 18 - read
ok 19 - status before restart
received HUP, spawning a new worker
starting new worker 31740
new worker is now running, sending USR1 to old workers:31718
sleeping 3 secs before killing old workers
killing old workers
ok 20 - status during restart
old worker 31718 died, status:0
ok 21 - status after restart
ok 22 - signal sent on hup
ok 23 - reconnect
ok 24 - write after switching
ok 25 - read after switching
ok 26 - read after swiching (format)
ok 27 - pid should have changed
received TERM, sending TERM to all workers:31740

while usually the end looks like:

...
ok 27 - pid should have changed
received TERM, sending TERM to all workers:31308
worker 31308 died, status:0
exiting
[Test::TCP] Child process does not block(PID: 31255, PPID: 30855) at /usr/share/perl5/Test/TCP.pm line 103.
ok 28 - no more status file
ok

5) Some older failures on ci.d.n also point to t/00-base.t instead of
   t/04-starter-dir.t, e.g.
   https://ci.debian.net/data/packages/unstable/amd64/libs/libserver-starter-perl/20160601_074345.autopkgtest.log.gz

adt-run [07:45:24]: test command1: /usr/share/pkg-perl-autopkgtest/runner build-deps
adt-run [07:45:24]: test command1: [-----------------------
t/00-base.t ............ 
1..1
ok 1 - use Server::Starter;
ok
adt-run [10:32:04]: ERROR: timed out on command ...

   t/00-base.t only does "use_ok('Server::Starter');" ...

   So maybe the problem is really not in one specific test but in the
   code itself. Somewhere.



Cheers,
gregor

-- 
 .''`.  Homepage https://info.comodo.priv.at/ - OpenPGP key 0xBB3A68018649AA06
 : :' : Debian GNU/Linux user, admin, and developer -  https://www.debian.org/
 `. `'  Member of VIBE!AT & SPI, fellow of the Free Software Foundation Europe
   `-   NP: Various Artists: Katie
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 931 bytes
Desc: Digital Signature
URL: <http://lists.alioth.debian.org/pipermail/pkg-perl-maintainers/attachments/20161022/7ec3aa0e/attachment.sig>