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

Paul Gevers Thu, 29 Dec 2022 11:15:16 -0800

Hi,

On Sun, 14 Aug 2022 09:20:57 +0200 Lucas Nussbaum <lu...@debian.org> wrote:

Source: ruby-parallel
Version: 1.22.1-1
Severity: serious
Justification: FTBFS
Tags: bookworm sid ftbfs
User: lu...@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

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

Index: ruby-parallel/spec/parallel_spec.rb
===================================================================
--- ruby-parallel.orig/spec/parallel_spec.rb
+++ ruby-parallel/spec/parallel_spec.rb
@@ -23,9 +23,9 @@ describe Parallel do
     t = nil
     lambda {
       t = Thread.new { ruby("spec/cases/parallel_start_and_kill.rb #{command} 2>&1 && echo 'FINISHED'") }
-      sleep 1.5
+      sleep 10
       kill_process_with_name('spec/cases/parallel_start_and_kill.rb', signal)
-      sleep 1
+      sleep 10
     }.should change { `ps`.split("\n").size }.by amount
     t.value
   end
@@ -103,20 +103,20 @@ describe Parallel do
       time_taken do
         result = execute_start_and_kill "PROCESS", 0
         result.should_not include "FINISHED"
-      end.should be <= 3
+      end.should be <= 30
     end
 
     it "kills the processes when the main process gets killed through a custom interrupt" do
       time_taken do
         execute_start_and_kill "PROCESS SIGTERM", 0, "TERM"
-      end.should be <= 3
+      end.should be <= 30
     end
 
     it "kills the threads when the main process gets killed through ctrl+c" do
       time_taken do
         result = execute_start_and_kill "THREAD", 0
         result.should_not include "FINISHED"
-      end.should be <= 3
+      end.should be <= 30
     end
 
     it "does not kill processes when the main process gets sent an interrupt besides the custom interrupt" do
@@ -125,7 +125,7 @@ describe Parallel do
         result.should include 'FINISHED'
         result.should include 'Wrapper caught SIGINT'
         result.should include 'I should have been killed earlier'
-      end.should be <= 7
+      end.should be <= 60
     end
 
     it "does not kill threads when the main process gets sent an interrupt besides the custom interrupt" do
@@ -134,7 +134,7 @@ describe Parallel do
         result.should include 'FINISHED'
         result.should include 'Wrapper caught SIGINT'
         result.should include 'I should have been killed earlier'
-      end.should be <= 7
+      end.should be <= 60
     end
 
     it "does not kill anything on ctrl+c when everything has finished" do
@@ -146,7 +146,7 @@ describe Parallel do
         result = t.value
         result.scan(/I finished/).size.should == 3
         result.should_not include("Parallel execution interrupted")
-      end.should <= 4
+      end.should <= 60
     end
 
     it "preserves original intrrupts" do

OpenPGP_signature
Description: OpenPGP digital signature

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

Reply via email to