Result of trunk-gc-asserts@phosphorus-docker at 2022-09-28 00:30:07 +0900

• NG (95d5b33ea0)[LOG]
• test-all: 22352 tests, 5996080 assertions, 0 failures, 0 errors, 126 skips
• test-spec:
• commands:

  "make update-unicode  DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
  "make update-download DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
  "make update-rubyspec DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
  "make update-src      DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
  "make after-update    DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
  "make miniruby DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
  "make ruby DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
  "make all DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
  "make install DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
  "make yes-btest TESTOPTS='-q -j6'" exit with 0.
  "make yes-test-basic TESTS='-j6'" exit with 0.
  make yes-test-all TESTOPTS='--stderr-on-failure' TESTS='-j6'
  $$$ #<Timeout::Error: execution expired>
  ### enter analyzing mode for stuck processes
  $$$ ps jx
   PPID   PID  PGID   SID TTY      TPGID STAT   UID   TIME COMMAND
     10    11    11    11 ?           -1 Ss    1001   0:00 sh build-loop.sh trunk-gc-asserts --incremental --process-num=6
      1   665    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:45039
      1   908    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby /tmp/ruby/v3/src/trunk-gc-asserts/test/drb/ut_drb.rb druby://localhost:39057 ut_drb.rb
      1  2156    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:34273
      1  3267    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:33349
      1  4340    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:33313
      1  5717    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:38737
      1  6893    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:45715
      1 12152    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:41133
      1 13258    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:42447
      1 17705    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby /tmp/ruby/v3/src/trunk-gc-asserts/test/drb/ut_drb.rb druby://localhost:43515 ut_drb.rb
     11 18887    11    11 ?           -1 Sl    1001   0:00 ruby ./br.rb build_report trunk-gc-asserts --incremental --process-num=6
  18887 18890    11    11 ?           -1 S     1001   0:00 sh -c ruby /home/ko1/ruby/build-ruby/build-ruby.rb --target_name=trunk-gc-asserts --logfile=/home/ko1/ruby/logs/brlog.trunk-gc-asserts.20220927-092541 --root_dir=/tmp/ruby --timeout=21600 --build_opts='DEFS="-DRGENGC_CHECK_MODE=2"'                              --add-env=RUBY_TEST_SUBPROCESS_TIMEOUT_SCALE=30 --incremental --process-num=6
  18890 18891    11    11 ?           -1 Sl    1001   0:00 ruby /home/ko1/ruby/build-ruby/build-ruby.rb --target_name=trunk-gc-asserts --logfile=/home/ko1/ruby/logs/brlog.trunk-gc-asserts.20220927-092541 --root_dir=/tmp/ruby --timeout=21600 --build_opts=DEFS="-DRGENGC_CHECK_MODE=2" --add-env=RUBY_TEST_SUBPROCESS_TIMEOUT_SCALE=30 --incremental --process-num=6
      1 19235    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:37463
      1 20556    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:35461
  18891 22061    11    11 ?           -1 Z     1001   0:00 [sh] <defunct>
      1 23936    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:41085
      1 23982    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:38353
      1 24161    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:34271
      1 25076    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:41515
      1 26125    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:40905
      1 26665    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:33615
      1 28690    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:35033
  18891 31783    11    11 ?           -1 R     1001   0:00 ps jx
      1 32413    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:39277
      1 32417    11    11 ?           -1 Sl    1001   0:01 /tmp/ruby/v3/build/trunk-gc-asserts/ruby -rdrb/drb -rdrb/eq -rrinda/ring -rrinda/tuplespace -e       uri = ARGV[0]       DRb.start_service("druby://localhost:0")       ro = DRbObject.new_with_uri(uri)       ts = Rinda::TupleSpaceProxy.new(ro)       th = Thread.new do         ts.take([:test_take, nil])       rescue Interrupt         # Expected       end       Kernel.sleep(0.1)       th.raise(Interrupt) # causes loss of the taken tuple       ts.write([:barrier, :continue])       Kernel.sleep  druby://localhost:35747
  {10=>[11], 1=>[665, 908, 2156, 3267, 4340, 5717, 6893, 12152, 13258, 17705, 19235, 20556, 23936, 23982, 24161, 25076, 26125, 26665, 28690, 32413, 32417], 11=>[18887], 18887=>[18890], 18890=>[18891], 18891=>[22061, 31783]}
  $ timeout 60 gdb -p 22061 -x /home/ko1/ruby/build-ruby/gdbscript -batch -quiet 2> /dev/null
  >>> Threads
  No threads.
  >>> Machine level backtrace
  >>> Dump Ruby level backtrace (if possible)
  $ timeout 60 gdb -p 31783 -x /home/ko1/ruby/build-ruby/gdbscript -batch -quiet 2> /dev/null
  >>> Threads
  No threads.
  >>> Machine level backtrace
  >>> Dump Ruby level backtrace (if possible)
  #<Errno::ESRCH: No such process>
  

• Linux phosphorus-docker 4.9.0-19-amd64 #1 SMP Debian 4.9.320-2 (2022-06-30) x86_64 x86_64 x86_64 GNU/Linux
  

• Logfile: /home/ko1/ruby/logs/brlog.trunk-gc-asserts.20220927-092541
  #<BuildRuby:0x0000561055bf37c0
   @BUILD_DIR="/tmp/ruby/v3/build",
   @INSTALL_DIR="/tmp/ruby/v3/install",
   @REPOSITORY="https://github.com/ruby/ruby.git",
   @REPOSITORY_TYPE=:git,
   @SRC_DIR="/tmp/ruby/v3/src",
   @TARGET_BUILD_DIR="/tmp/ruby/v3/build/trunk-gc-asserts",
   @TARGET_INSTALL_DIR="/tmp/ruby/v3/install/trunk-gc-asserts",
   @TARGET_NAME="trunk-gc-asserts",
   @TARGET_SRC_DIR="/tmp/ruby/v3/src/trunk-gc-asserts",
   @btest_opts="-j6",
   @build_opts="DEFS=\"-DRGENGC_CHECK_MODE=2\"",
   @configure_opts=["--enable-shared"],
   @gist=false,
   @git_branch=nil,
   @git_worktree=nil,
   @incremental=true,
   @logfile="/home/ko1/ruby/logs/brlog.trunk-gc-asserts.20220927-092541",
   @make="make",
   @quiet=false,
   @ruby_env=
    [["RUBY_DEBUG", "ci"], ["RUBY_TEST_SUBPROCESS_TIMEOUT_SCALE", "30"]],
   @steps=
    ["checkout",
     "autoconf",
     "configure",
     "build_up",
     "build_miniruby",
     "build_ruby",
     "build_all",
     "build_install",
     "test_btest",
     "test_basic",
     "test_all",
     "test_rubyspec"],
   @svn_revision=nil,
   @test_opts="TESTS='-j6'",
   @timeout=21600>
                             user     system      total        real
  checkout               0.000000   0.000000   0.000000 (  0.000019)
  autoconf               0.000000   0.000000   0.000000 (  0.000043)
  configure              0.000000   0.000000   0.000000 (  0.000053)
  build_up               0.008000   0.004000   3.172000 (  4.016199)
  build_miniruby         0.004000   0.000000   0.268000 (  0.302876)
  build_ruby             0.004000   0.000000   0.248000 (  0.279431)
  build_all              0.012000   0.000000   4.480000 (  5.222686)
  build_install          0.024000   0.012000  12.668000 ( 13.393170)
  test_btest             0.000000   0.000000 744.460000 (235.051251)
  test_basic             0.016000   0.000000   5.764000 (  6.298668)
  test_all             #<Thread:0x0000561055c7d358 /home/ko1/ruby/build-ruby/build-ruby.rb:209 run> terminated with exception (report_on_exception is true):
  /home/ko1/ruby/build-ruby/build-ruby.rb:209:in `each_line': stream closed in another thread (IOError)
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:209:in `block (2 levels) in cmd'
    0.004000   0.008000 17947.432000 (21600.485848)
  /home/ko1/ruby/build-ruby/build-ruby.rb:214:in `join': execution expired (Timeout::Error)
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:214:in `each'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:214:in `block (2 levels) in cmd'
  	from /usr/lib/ruby/2.7.0/timeout.rb:110:in `timeout'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:213:in `block in cmd'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:205:in `popen'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:205:in `cmd'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:380:in `block in test_all'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:300:in `block in builddir'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:299:in `chdir'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:299:in `builddir'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:378:in `test_all'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:442:in `block (4 levels) in run'
  	from /usr/lib/ruby/2.7.0/benchmark.rb:293:in `measure'
  	from /usr/lib/ruby/2.7.0/benchmark.rb:375:in `item'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:440:in `block (3 levels) in run'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:439:in `each'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:439:in `block (2 levels) in run'
  	from /usr/lib/ruby/2.7.0/benchmark.rb:173:in `benchmark'
  	from /usr/lib/ruby/2.7.0/benchmark.rb:205:in `bm'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:438:in `block in run'
  	from /usr/lib/ruby/2.7.0/benchmark.rb:293:in `measure'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:437:in `run'
  	from /home/ko1/ruby/build-ruby/build-ruby.rb:631:in `<main>'
  total: 21865.05 sec