Bug#923829: starlet: FTBFS randomly (failing tests)

Tue Mar 5 19:10:00 GMT 2019

Package: src:starlet
Version: 0.31-1
Severity: important
Tags: ftbfs

Dear maintainer:

I tried to build this package in buster but it failed:

--------------------------------------------------------------------------------
[...]
 debian/rules build-indep
dh build-indep
   dh_update_autotools_config -i
   dh_auto_configure -i
	perl -I. Makefile.PL INSTALLDIRS=vendor "OPTIMIZE=-g -O2 -fdebug-prefix-map=/<<PKGBUILDDIR>>=. -fstack-protector-strong -Wformat -Werror=format-security -Wdate-time -D_FORTIFY_SOURCE=2" "LD=x86_64-linux-gnu-gcc -g -O2 -fdebug-prefix-map=/<<PKGBUILDDIR>>=. -fstack-protector-strong -Wformat -Werror=format-security -Wl,-z,relro"
Checking if your kit is complete...
Looks good
Generating a Unix-style Makefile
Writing Makefile for Starlet
Writing MYMETA.yml and MYMETA.json
   dh_auto_build -i
	make -j1
make[1]: Entering directory '/<<PKGBUILDDIR>>'
cp lib/Starlet.pm blib/lib/Starlet.pm
cp lib/Starlet/Server.pm blib/lib/Starlet/Server.pm
cp lib/Plack/Handler/Starlet.pm blib/lib/Plack/Handler/Starlet.pm
Manifying 1 pod document
make[1]: Leaving directory '/<<PKGBUILDDIR>>'
   dh_auto_test -i
	make -j1 test TEST_VERBOSE=1
make[1]: Entering directory '/<<PKGBUILDDIR>>'
PERL_DL_NONLAZY=1 "/usr/bin/perl" "-MExtUtils::Command::MM" "-MTest::Harness" "-e" "undef *Test::Harness::Switches; test_harness(1, 'inc', 'blib/lib', 'blib/arch')" t/*.t
start_server (pid:17048) starting now...
starting new worker 17049
Plack::Handler::Starlet: Accepting connections at http://0:34873/
127.0.0.1 - - [05/Mar/2019:15:11:17 +0000] "GET / HTTP/1.1" 200 5 "-" "libwww-perl/6.36"
received TERM, sending TERM to all workers:17049
worker 17049 died, status:0
exiting
t/00base.t ................. 
ok 1 - use Server::Starter;
ok 2 - request successfull
ok 3 - content is hello
1..3
ok
t/01plack-test.t ........... 
# SCRIPT_NAME
ok 1
# GET
ok 2
ok 3
ok 4
ok 5
# POST
ok 6
ok 7
ok 8
ok 9
ok 10
ok 11
# big POST
ok 12
ok 13
ok 14
ok 15
ok 16
# psgi.url_scheme
ok 17
ok 18
ok 19
ok 20
# return glob
ok 21
ok 22
ok 23
ok 24
ok 25
# filehandle
ok 26
ok 27
ok 28
ok 29
# bigger file
ok 30
ok 31
ok 32
ok 33
ok 34
# handle HTTP-Header
ok 35
ok 36
ok 37
ok 38
# handle HTTP-Cookie
ok 39
ok 40
ok 41
ok 42
# validate env
ok 43
ok 44
ok 45
ok 46
# % encoding in PATH_INFO
ok 47 - PATH_INFO should be decoded per RFC 3875
# % double encoding in PATH_INFO
ok 48 - PATH_INFO should be decoded only once, per RFC 3875
# % encoding in PATH_INFO (outside of URI characters)
ok 49
# SERVER_PROTOCOL is required
ok 50
ok 51
ok 52
ok 53
# SCRIPT_NAME should not be undef
ok 54
# call close after read IO::Handle-like
ok 55 - closed
ok 56
# has errors
ok 57
# status line
ok 58
# Do not crash when the app dies
ok 59
ok 60
# multi headers (request)
ok 61
# multi headers (response)
ok 62
# Do not set $env->{COOKIE}
ok 63
ok 64
# no entity headers on 304
ok 65
ok 66
ok 67
ok 68 - No Content-Type
ok 69 - No Content-Length
ok 70 - No Transfer-Encoding
# REQUEST_URI is set
ok 71
# filehandle with path()
ok 72
ok 73
ok 74
ok 75
# a big header value > 128 bytes
ok 76
ok 77
ok 78
# coderef res
ok 79
ok 80
ok 81
ok 82
# coderef streaming
ok 83
ok 84
ok 85
ok 86
# CRLF output and FCGI parse bug
ok 87
ok 88
# newlines
ok 89
# test 404
ok 90
ok 91
ok 92
# request->input seekable
ok 93
# request->content on GET
ok 94
# handle Authorization header
ok 95
ok 96
ok 97
ok 98
# repeated slashes
ok 99
ok 100
ok 101
ok 102
1..102
ok
17080 at t/02graceful.t line 11.
17080 at t/02graceful.t line 30.
17083 at t/02graceful.t line 16.
t/02graceful.t ............. 
ok 1
1..1
ok
17097 at t/03post.t line 9.
Plack::Handler::Starlet: Accepting connections at http://0:46299/
127.0.0.1 - - [05/Mar/2019:15:11:20 +0000] "POST / HTTP/1.1" 200 3 "-" "libwww-perl/6.36"
t/03post.t ................. 
# send a broken request
# send next request
ok 1
ok 2
ok 3
1..3
ok
t/04-bumpy-life.t .......... 
ok 1 - min
ok 2 - max
1..2
ok
t/05server-header.t ........ 
ok 1
ok 2
ok 3
ok 4
ok 5
ok 6
1..6
ok
t/06harakiri.t ............. 
ok 1 - In non-harakiri mode, pid is reused
ok 2 - In Harakiri mode, each pid only used once
1..2
ok
t/07remote_port.t .......... 
ok 1
ok 2
1..2
ok
t/08chunked_req.t .......... 
ok 1
ok 2
1..2
ok
t/09chunked_zero_length.t .. 
ok 1
1..1
ok
t/10unix_domain_socket.t ... 
# Subtest: direct
    ok 1
    ok 2
    1..2
ok 1 - direct
# Subtest: server-starter
    ok 1
    ok 2
    1..2
ok 2 - server-starter
1..2
ok
t/11multi-sockets.t ........ 
ok 1
ok 2
ok 3
ok 4
ok 5
ok 6
ok 7
ok 8
ok 9
ok 10
ok 11
ok 12
ok 13
ok 14
1..14
ok
#   Failed test 'No warnings'
#   at t/12bad_request_line.t line 24.
# SIGTERM handler "DEFAULT" not defined.
# Looks like you failed 1 test of 2.
t/12bad_request_line.t ..... 
ok 1
# HTTP/1.1 400 Bad Request

# Date: Tue, 05 Mar 2019 15:11:30 GMT

# Server: Plack::Handler::Starlet

# Content-Type: text/plain

# Connection: close

# 

# Bad Request
not ok 2 - No warnings
1..2
Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/2 subtests 
start_server (pid:17259) starting now...
starting new worker 17260
Plack::Handler::Starlet: Accepting connections at http://0:42303/
received HUP, spawning a new worker
starting new worker 17288
Plack::Handler::Starlet: Accepting connections at http://0:42303/
new worker is now running, sending USR1 to old workers:17260
killing old workers
received TERM, sending TERM to all workers:17260,17288
worker 17260 died, status:0
worker 17288 died, status:0
exiting
t/13spawn_interval.t ....... 
ok 1 - use Server::Starter;
ok 2 - process still alive before HUP signal
ok 3 - old generation process still alive for a while after HUP signal
1..3
ok
Plack::Handler::Starlet: Accepting connections at http://0:5000/
t/14child_finish_hook.t .... 
1..1
ok 1 - child_exit has been executed.
ok

Test Summary Report
-------------------
t/12bad_request_line.t   (Wstat: 256 Tests: 2 Failed: 1)
  Failed test:  2
  Non-zero exit status: 1
Files=15, Tests=146, 27 wallclock secs ( 0.14 usr  0.05 sys +  7.02 cusr  2.45 csys =  9.66 CPU)
Result: FAIL
Failed 1/15 test programs. 1/146 subtests failed.
make[1]: *** [Makefile:762: test_dynamic] Error 255
make[1]: Leaving directory '/<<PKGBUILDDIR>>'
dh_auto_test: make -j1 test TEST_VERBOSE=1 returned exit code 2
make: *** [debian/rules:4: build-indep] Error 2
dpkg-buildpackage: error: debian/rules build-indep subprocess returned exit status 2
--------------------------------------------------------------------------------

The build was made in one of my autobuilders with "dpkg-buildpackage -A".

The failure happens randomly, i.e. sometimes it fails, sometimes it does not,
so I don't have a "recipe" to reproduce it as such, but the "randomness"
is reproducible in my autobuilders (i.e. when I build it a lot of times,
there are always some failed builds).

I've put several failed build logs here for reference:

https://people.debian.org/~sanvila/build-logs/starlet/

If you need a test machine to reproduce this, please contact me
privately and I could provide ssh access to a machine where it happens
(caveat: randomly and maybe with low probability).

If this is really a bug in one of the build-depends, please use reassign and affects,
so that this is still visible in the BTS web page for this package.

Thanks.