[DRE-maint] Bug#1017218: ruby-parallel: FTBFS: E: Build killed with signal TERM after 150 minutes of inactivity

Paul Gevers elbrus at debian.org
Thu Dec 29 19:12:21 GMT 2022


Hi,

On Sun, 14 Aug 2022 09:20:57 +0200 Lucas Nussbaum <lucas at debian.org> wrote:
> Source: ruby-parallel
> Version: 1.22.1-1
> Severity: serious
> Justification: FTBFS
> Tags: bookworm sid ftbfs
> User: lucas at debian.org
> Usertags: ftbfs-20220813 ftbfs-bookworm
> 
> Hi,
> 
> During a rebuild of all packages in sid, your package failed to build
> on amd64.
> 
> 
> Relevant part (hopefully):
> >      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'
> > 
> > Finished in 1 minute 44.28 seconds (files took 0.10294 seconds to load)
> > 152 examples, 1 failure, 4 pending
> > 
> > Failed examples:
> > 
> > rspec './spec/parallel_spec.rb[1:10:30]' # Parallel.each does not call the finish hook when a worker fails with ractors
> > 
> > /usr/bin/ruby3.0 -I/usr/share/rubygems-integration/all/gems/rspec-support-3.10.3/lib:/usr/share/rubygems-integration/all/gems/rspec-core-3.10.1/lib /usr/share/rubygems-integration/all/gems/rspec-core-3.10.1/exe/rspec --pattern ./spec/\*\*/\*_spec.rb --format documentation failed
> > mv ./.gem2deb.Gemfile.lock Gemfile.lock
> > ERROR: Test "ruby3.0" failed. Exiting.
> > dh_auto_install: error: dh_ruby --install /<<PKGBUILDDIR>>/debian/ruby-parallel returned exit code 1
> > make: *** [debian/rules:7: binary] Error 25
> > dpkg-buildpackage: error: debian/rules binary subprocess returned exit status 2
> > E: Build killed with signal TERM after 150 minutes of inactivity

While trying to find out which test was the potential culprit of this 
issue (I guess something kept running instead of being killed/closed), I 
ran into multiple different failures depending on my retry attempt (see 
some below). So, it seems these tests are particularly sensitive to the 
load of the system (I regularly hit timeouts). I think it's best to 
disable the build test (and potentially also the autopkgtest, albeit I 
haven't seen that fail very often yet).

Paul
PS, I tried the attached patch, but that seems to have pushed some times 
out of reasonable limits as I was getting very different errors.

E.g. currently on reproducible-builds.org:
https://tests.reproducible-builds.org/debian/logs/bookworm/amd64/ruby-parallel_1.22.1-1.build2.log.gz

Failures:

   1) Parallel.in_processes kills the processes when the main process 
gets killed through ctrl+c
      Failure/Error:
        time_taken do
          result = execute_start_and_kill "PROCESS", 0
          result.should_not include "FINISHED"
        end.should be <= 3

        expected: <= 3
             got:    3.4196298122406006
      # ./spec/parallel_spec.rb:103:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

   2) Parallel.in_processes kills the processes when the main process 
gets killed through a custom interrupt
      Failure/Error:
        lambda {
          t = Thread.new { ruby("spec/cases/parallel_start_and_kill.rb 
#{command} 2>&1 && echo 'FINISHED'") }
          sleep 1.5
 
kill_process_with_name('spec/cases/parallel_start_and_kill.rb', signal)
          sleep 1
        }.should change { `ps`.split("\n").size }.by amount

        expected ``ps`.split("\n").size` to have changed by 0, but was 
changed by 19
      # ./spec/parallel_spec.rb:24:in `execute_start_and_kill'
      # ./spec/parallel_spec.rb:111:in `block (4 levels) in <top 
(required)>'
      # ./spec/parallel_spec.rb:11:in `time_taken'
      # ./spec/parallel_spec.rb:110:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

   3) Parallel.in_processes kills the threads when the main process gets 
killed through ctrl+c
      Failure/Error:
        lambda {
          t = Thread.new { ruby("spec/cases/parallel_start_and_kill.rb 
#{command} 2>&1 && echo 'FINISHED'") }
          sleep 1.5
 
kill_process_with_name('spec/cases/parallel_start_and_kill.rb', signal)
          sleep 1
        }.should change { `ps`.split("\n").size }.by amount

        expected ``ps`.split("\n").size` to have changed by 0, but was 
changed by -20
      # ./spec/parallel_spec.rb:24:in `execute_start_and_kill'
      # ./spec/parallel_spec.rb:117:in `block (4 levels) in <top 
(required)>'
      # ./spec/parallel_spec.rb:11:in `time_taken'
      # ./spec/parallel_spec.rb:116:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

   4) Parallel.in_processes does not kill processes when the main 
process gets sent an interrupt besides the custom interrupt
      Failure/Error:
        lambda {
          t = Thread.new { ruby("spec/cases/parallel_start_and_kill.rb 
#{command} 2>&1 && echo 'FINISHED'") }
          sleep 1.5
 
kill_process_with_name('spec/cases/parallel_start_and_kill.rb', signal)
          sleep 1
        }.should change { `ps`.split("\n").size }.by amount

        expected ``ps`.split("\n").size` to have changed by 4, but was 
changed by -18
      # ./spec/parallel_spec.rb:24:in `execute_start_and_kill'
      # ./spec/parallel_spec.rb:124:in `block (4 levels) in <top 
(required)>'
      # ./spec/parallel_spec.rb:11:in `time_taken'
      # ./spec/parallel_spec.rb:123:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

   5) Parallel.in_processes does not kill threads when the main process 
gets sent an interrupt besides the custom interrupt
      Failure/Error:
        lambda {
          t = Thread.new { ruby("spec/cases/parallel_start_and_kill.rb 
#{command} 2>&1 && echo 'FINISHED'") }
          sleep 1.5
 
kill_process_with_name('spec/cases/parallel_start_and_kill.rb', signal)
          sleep 1
        }.should change { `ps`.split("\n").size }.by amount

        expected ``ps`.split("\n").size` to have changed by 2, but was 
changed by 4
      # ./spec/parallel_spec.rb:24:in `execute_start_and_kill'
      # ./spec/parallel_spec.rb:133:in `block (4 levels) in <top 
(required)>'
      # ./spec/parallel_spec.rb:11:in `time_taken'
      # ./spec/parallel_spec.rb:132:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

   6) Parallel.in_threads does not create new processes
      Failure/Error: -> { Thread.new { Parallel.in_threads(2) { sleep 1 
} } }.should_not(change { `ps`.split("\n").size })
        expected ``ps`.split("\n").size` not to have changed, but did 
change from 251 to 249
      # ./spec/parallel_spec.rb:212:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

Finished in 3 minutes 8.1 seconds (files took 0.98045 seconds to load)
152 examples, 6 failures, 4 pending

Failed examples:

rspec ./spec/parallel_spec.rb:102 # Parallel.in_processes kills the 
processes when the main process gets killed through ctrl+c
rspec ./spec/parallel_spec.rb:109 # Parallel.in_processes kills the 
processes when the main process gets killed through a custom interrupt
rspec ./spec/parallel_spec.rb:115 # Parallel.in_processes kills the 
threads when the main process gets killed through ctrl+c
rspec ./spec/parallel_spec.rb:122 # Parallel.in_processes does not kill 
processes when the main process gets sent an interrupt besides the 
custom interrupt
rspec ./spec/parallel_spec.rb:131 # Parallel.in_processes does not kill 
threads when the main process gets sent an interrupt besides the custom 
interrupt
rspec ./spec/parallel_spec.rb:211 # Parallel.in_threads does not create 
new processes


https://ci.debian.net/data/autopkgtest/unstable/armel/r/ruby-parallel/28972844/log.gz

Failures:

   1) Parallel GC does not leak memory in ractors
      Failure/Error: `#{RbConfig.ruby} #{cmd}`

      Timeout::Error:
        execution expired
      # ./spec/spec_helper.rb:13:in ``'
      # ./spec/spec_helper.rb:13:in `ruby'
      # ./spec/parallel_spec.rb:732:in `block (4 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

Finished in 2 minutes 6.3 seconds (files took 0.15343 seconds to load)
152 examples, 1 failure, 4 pending

Failed examples:

rspec ./spec/parallel_spec.rb[1:16:3] # Parallel GC does not leak memory 
in ractors

/usr/bin/ruby3.1 
-I/usr/share/rubygems-integration/all/gems/rspec-support-3.10.3/lib:/usr/share/rubygems-integration/all/gems/rspec-core-3.10.1/lib 
/usr/share/rubygems-integration/all/gems/rspec-core-3.10.1/exe/rspec 
--pattern ./spec/\*\*/\*_spec.rb --format documentation failed
mv ./.gem2deb.lib lib
mv ./.gem2deb.Gemfile.lock Gemfile.lock
/tmp/autopkgtest-lxc.arvkp_98/downtmp/wrapper.sh: Killing leaked 
background processes: 3534
     PID TTY      STAT   TIME COMMAND
    3534 ?        S      0:00 sh -c /usr/bin/ruby3.1 
spec/cases/profile_memory.rb ractors 2>&1


https://ci.debian.net/data/autopkgtest/unstable/riscv64/r/ruby-parallel/28973384/log.gz

Failures:

   1) Parallel.each does not slow down with lots of GC work in threads
      Failure/Error: `#{RbConfig.ruby} #{cmd}`

      Timeout::Error:
        execution expired
      # ./spec/spec_helper.rb:13:in ``'
      # ./spec/spec_helper.rb:13:in `ruby'
      # ./spec/parallel_spec.rb:589:in `block (4 levels) in <top 
(required)>'
      # ./spec/parallel_spec.rb:589:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

Finished in 3 minutes 53.9 seconds (files took 1.35 seconds to load)
152 examples, 1 failure, 4 pending

Failed examples:

rspec ./spec/parallel_spec.rb:588 # Parallel.each does not slow down 
with lots of GC work in threads

/usr/bin/ruby3.1 
-I/usr/share/rubygems-integration/all/gems/rspec-support-3.10.3/lib:/usr/share/rubygems-integration/all/gems/rspec-core-3.10.1/lib 
/usr/share/rubygems-integration/all/gems/rspec-core-3.10.1/exe/rspec 
--pattern ./spec/\*\*/\*_spec.rb --format documentation failed
mv ./.gem2deb.lib lib
mv ./.gem2deb.Gemfile.lock Gemfile.lock


local try (autopkgtest . -- lxc --sudo autopkgtest-unstable-amd64):
Failures:

   1) Parallel.in_processes does not leave processes behind while running
      Failure/Error: 
ruby("spec/cases/closes_processes_at_runtime.rb").gsub(/.* deprecated; 
use BigDecimal.*\n/, '').should == 'OK'

        expected: "OK"
             got: "FAIL: before:4 -- after:3" (using ==)
      # ./spec/parallel_spec.rb:195:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'


Several runs on on debomatic (during the autopkgtest):

Failures:

   1) Parallel.in_processes kills the processes when the main process 
gets killed through ctrl+c
      Failure/Error:
        lambda {
          t = Thread.new { ruby("spec/cases/parallel_start_and_kill.rb 
#{command} 2>&1 && echo 'FINISHED'") }
          sleep 1.5
 
kill_process_with_name('spec/cases/parallel_start_and_kill.rb', signal)
          sleep 1
        }.should change { `ps`.split("\n").size }.by amount

        expected ``ps`.split("\n").size` to have changed by 0, but was 
changed by 1
      # ./spec/parallel_spec.rb:24:in `execute_start_and_kill'
      # ./spec/parallel_spec.rb:104:in `block (4 levels) in <top 
(required)>'
      # ./spec/parallel_spec.rb:11:in `time_taken'
      # ./spec/parallel_spec.rb:103:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

   2) Parallel.in_processes kills the threads when the main process gets 
killed through ctrl+c
      Failure/Error:
        lambda {
          t = Thread.new { ruby("spec/cases/parallel_start_and_kill.rb 
#{command} 2>&1 && echo 'FINISHED'") }
          sleep 1.5
 
kill_process_with_name('spec/cases/parallel_start_and_kill.rb', signal)
          sleep 1
        }.should change { `ps`.split("\n").size }.by amount

        expected ``ps`.split("\n").size` to have changed by 0, but was 
changed by 1
      # ./spec/parallel_spec.rb:24:in `execute_start_and_kill'
      # ./spec/parallel_spec.rb:117:in `block (4 levels) in <top 
(required)>'
      # ./spec/parallel_spec.rb:11:in `time_taken'
      # ./spec/parallel_spec.rb:116:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

   3) Parallel.in_processes does not kill processes when the main 
process gets sent an interrupt besides the custom interrupt
      Failure/Error:
        lambda {
          t = Thread.new { ruby("spec/cases/parallel_start_and_kill.rb 
#{command} 2>&1 && echo 'FINISHED'") }
          sleep 1.5
     kill_process_with_name('spec/cases/parallel_start_and_kill.rb', signal)
          sleep 1
        }.should change { `ps`.split("\n").size }.by amount

        expected ``ps`.split("\n").size` to have changed by 4, but was 
changed by 3
      # ./spec/parallel_spec.rb:24:in `execute_start_and_kill'
      # ./spec/parallel_spec.rb:124:in `block (4 levels) in <top 
(required)>'
      # ./spec/parallel_spec.rb:11:in `time_taken'
      # ./spec/parallel_spec.rb:123:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

   4) Parallel.in_processes does not kill threads when the main process 
gets sent an interrupt besides the custom interrupt
      Failure/Error:
        lambda {
          t = Thread.new { ruby("spec/cases/parallel_start_and_kill.rb 
#{command} 2>&1 && echo 'FINISHED'") }
          sleep 1.5
 
kill_process_with_name('spec/cases/parallel_start_and_kill.rb', signal)
          sleep 1
        }.should change { `ps`.split("\n").size }.by amount

        expected ``ps`.split("\n").size` to have changed by 2, but was 
changed by -3
      # ./spec/parallel_spec.rb:24:in `execute_start_and_kill'
      # ./spec/parallel_spec.rb:133:in `block (4 levels) in <top 
(required)>'
      # ./spec/parallel_spec.rb:11:in `time_taken'
      # ./spec/parallel_spec.rb:132:in `block (3 levels) in <top 
(required)>'
      # ./spec/spec_helper.rb:9:in `block (2 levels) in <top (required)>'

Finished in 1 minute 19.53 seconds (files took 0.16823 seconds to load)
152 examples, 4 failures, 4 pending
-------------- next part --------------
A non-text attachment was scrubbed...
Name: raise-timeouts-in-tests.patch
Type: text/x-patch
Size: 2442 bytes
Desc: not available
URL: <http://alioth-lists.debian.net/pipermail/pkg-ruby-extras-maintainers/attachments/20221229/6b17314b/attachment-0001.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: OpenPGP_signature
Type: application/pgp-signature
Size: 495 bytes
Desc: OpenPGP digital signature
URL: <http://alioth-lists.debian.net/pipermail/pkg-ruby-extras-maintainers/attachments/20221229/6b17314b/attachment-0001.sig>


More information about the Pkg-ruby-extras-maintainers mailing list