Result of trunk-gc-asserts@ruby-sp2-docker at 2023-07-22 01:55:11 +0900

NG [LOG]
test-all: 25089 tests, 9215691 assertions, 0 failures, 0 errors, 146 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.
From https://github.com/ruby/typeprof
 * branch            aabc019684d8b4a1ed66c2a1ca48da7bbb18dcc0 -> FETCH_HEAD
HEAD is now at aabc019 Skip VM_CALL_BLOCKISEQ for Ruby < 3.3
"make update-rubyspec DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
"make update-src      DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 512.
From https://github.com/ruby/ruby
   8d9a25a..22f9735  master     -> origin/master
error: The following untracked working tree files would be overwritten by merge:
	test/yarp/snapshots/seattlerb/pct_w_heredoc_interp_nested.txt
Please move or remove them before you merge.
Aborting
make: *** [Makefile:565: update-src] Error 1
"make after-update    DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
From https://github.com/ruby/typeprof
 * branch            aabc019684d8b4a1ed66c2a1ca48da7bbb18dcc0 -> FETCH_HEAD
HEAD is now at aabc019 Skip VM_CALL_BLOCKISEQ for Ruby < 3.3
"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.
From https://github.com/ruby/typeprof
 * branch            aabc019684d8b4a1ed66c2a1ca48da7bbb18dcc0 -> FETCH_HEAD
HEAD is now at aabc019 Skip VM_CALL_BLOCKISEQ for Ruby < 3.3
"make yes-btest TESTOPTS='-q -j4'" exit with 0.
 
"make yes-test-basic TESTS='-j4'" exit with 0.
make yes-test-all TESTOPTS='--stderr-on-failure' TESTS='-j4'
$$$ #<Timeout::Error: execution expired>
### enter analyzing mode for stuck processes
$$$ ps jx
   PPID     PID    PGID     SID TTY        TPGID STAT   UID   TIME COMMAND
     11      12      12      12 ?             -1 Ss    1001   0:00 sh build-loop.sh trunk-gc-asserts --incremental --process-num=4
      1 1111922      12      12 ?             -1 Sl    1001   0:00 /tmp/ruby/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:45021
      1 1133200      12      12 ?             -1 Sl    1001   0:00 /tmp/ruby/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:35229
      1 1261812      12      12 ?             -1 Sl    1001   0:00 /tmp/ruby/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:39967
      1 1284301      12      12 ?             -1 Sl    1001   0:00 /tmp/ruby/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:35659
     12 1290239      12      12 ?             -1 Sl    1001   0:00 ruby ./br.rb build_report trunk-gc-asserts --incremental --process-num=4
1290239 1290242      12      12 ?             -1 S     1001   0:00 sh -c ruby /home/ko1/build-ruby/build-ruby.rb --target_name=trunk-gc-asserts --logfile=/home/ko1/ruby/logs/brlog.trunk-gc-asserts.20230721-105101 --root_dir=/tmp/ruby --timeout=21600 --build_opts='DEFS="-DRGENGC_CHECK_MODE=2"'                              --add-env=RUBY_TEST_SUBPROCESS_TIMEOUT_SCALE=30 --incremental --process-num=4
1290242 1290243      12      12 ?             -1 Sl    1001   0:00 ruby /home/ko1/build-ruby/build-ruby.rb --target_name=trunk-gc-asserts --logfile=/home/ko1/ruby/logs/brlog.trunk-gc-asserts.20230721-105101 --root_dir=/tmp/ruby --timeout=21600 --build_opts=DEFS="-DRGENGC_CHECK_MODE=2" --add-env=RUBY_TEST_SUBPROCESS_TIMEOUT_SCALE=30 --incremental --process-num=4
1290243 1294253      12      12 ?             -1 Z     1001   0:00 [sh] <defunct>
      1 1296972      12      12 ?             -1 Sl    1001   0:00 /tmp/ruby/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:35149
1290243 1301798      12      12 ?             -1 R     1001   0:00 ps jx
{11=>[12], 1=>[1111922, 1133200, 1261812, 1284301, 1296972], 12=>[1290239], 1290239=>[1290242], 1290242=>[1290243], 1290243=>[1294253, 1301798]}
$ timeout 60 gdb -p 1294253 -x /home/ko1/build-ruby/gdbscript -batch -quiet 2> /dev/null
>>> Threads
No threads.
>>> Machine level backtrace
>>> Dump Ruby level backtrace (if possible)
$ timeout 60 gdb -p 1301798 -x /home/ko1/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 ruby-sp2-docker 5.15.0-72-generic #79-Ubuntu SMP Wed Apr 19 08:22:18 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

Logfile: /home/ko1/ruby/logs/brlog.trunk-gc-asserts.20230721-105101
#<BuildRuby:0x000055e843f85b48
 @BUILD_DIR="/tmp/ruby/build",
 @INSTALL_DIR="/tmp/ruby/install",
 @REPOSITORY="https://github.com/ruby/ruby.git",
 @REPOSITORY_TYPE=:git,
 @SRC_DIR="/tmp/ruby/src",
 @TARGET_BUILD_DIR="/tmp/ruby/build/trunk-gc-asserts",
 @TARGET_INSTALL_DIR="/tmp/ruby/install/trunk-gc-asserts",
 @TARGET_NAME="trunk-gc-asserts",
 @TARGET_SRC_DIR="/tmp/ruby/src/trunk-gc-asserts",
 @btest_opts="-j4",
 @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.20230721-105101",
 @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='-j4'",
 @timeout=21600>
                           user     system      total        real
checkout               0.000014   0.000003   0.000017 (  0.000017)
autoconf               0.000021   0.000004   0.000025 (  0.000025)
configure              0.000022   0.000004   0.000026 (  0.000027)
build_up               0.001243   0.006016   2.260075 (  4.042674)
build_miniruby         0.000000   0.001686   1.681241 (  2.621538)
build_ruby             0.000000   0.001766   9.533758 ( 13.223270)
build_all              0.010536   0.004700  16.078226 ( 16.278974)
build_install          0.015659   0.005287   9.983374 ( 10.650839)
test_btest             0.000542   0.000176 500.762983 (198.406661)
test_basic             0.001971   0.006552   4.111015 (  4.048710)
test_all             #<Thread:0x000055e84401cbb0 /home/ko1/build-ruby/build-ruby.rb:209 run> terminated with exception (report_on_exception is true):
/home/ko1/build-ruby/build-ruby.rb:209:in `each_line': stream closed in another thread (IOError)
	from /home/ko1/build-ruby/build-ruby.rb:209:in `block (2 levels) in cmd'
  0.004658   0.000407 16712.789749 (21600.990195)
/home/ko1/build-ruby/build-ruby.rb:214:in `join': execution expired (Timeout::Error)
	from /home/ko1/build-ruby/build-ruby.rb:214:in `each'
	from /home/ko1/build-ruby/build-ruby.rb:214:in `block (2 levels) in cmd'
	from /usr/lib/ruby/3.0.0/timeout.rb:112:in `timeout'
	from /home/ko1/build-ruby/build-ruby.rb:213:in `block in cmd'
	from /home/ko1/build-ruby/build-ruby.rb:205:in `popen'
	from /home/ko1/build-ruby/build-ruby.rb:205:in `cmd'
	from /home/ko1/build-ruby/build-ruby.rb:381:in `block in test_all'
	from /home/ko1/build-ruby/build-ruby.rb:301:in `block in builddir'
	from /home/ko1/build-ruby/build-ruby.rb:300:in `chdir'
	from /home/ko1/build-ruby/build-ruby.rb:300:in `builddir'
	from /home/ko1/build-ruby/build-ruby.rb:379:in `test_all'
	from /home/ko1/build-ruby/build-ruby.rb:443:in `block (4 levels) in run'
	from /usr/lib/ruby/3.0.0/benchmark.rb:293:in `measure'
	from /usr/lib/ruby/3.0.0/benchmark.rb:375:in `item'
	from /home/ko1/build-ruby/build-ruby.rb:441:in `block (3 levels) in run'
	from /home/ko1/build-ruby/build-ruby.rb:440:in `each'
	from /home/ko1/build-ruby/build-ruby.rb:440:in `block (2 levels) in run'
	from /usr/lib/ruby/3.0.0/benchmark.rb:173:in `benchmark'
	from /usr/lib/ruby/3.0.0/benchmark.rb:205:in `bm'
	from /home/ko1/build-ruby/build-ruby.rb:439:in `block in run'
	from /usr/lib/ruby/3.0.0/benchmark.rb:293:in `measure'
	from /home/ko1/build-ruby/build-ruby.rb:438:in `run'
	from /home/ko1/build-ruby/build-ruby.rb:632:in `<main>'
total: 21850.26 sec

	"make update-unicode DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
	"make update-download DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
	From https://github.com/ruby/typeprof
	* branch aabc019684d8b4a1ed66c2a1ca48da7bbb18dcc0 -> FETCH_HEAD
	HEAD is now at aabc019 Skip VM_CALL_BLOCKISEQ for Ruby < 3.3
	"make update-rubyspec DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
	"make update-src DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 512.
	From https://github.com/ruby/ruby
	8d9a25a..22f9735 master -> origin/master
	error: The following untracked working tree files would be overwritten by merge:
	test/yarp/snapshots/seattlerb/pct_w_heredoc_interp_nested.txt
	Please move or remove them before you merge.
	Aborting
	make: *** [Makefile:565: update-src] Error 1
	"make after-update DEFS=\"-DRGENGC_CHECK_MODE=2\"" exit with 0.
	From https://github.com/ruby/typeprof
	* branch aabc019684d8b4a1ed66c2a1ca48da7bbb18dcc0 -> FETCH_HEAD
	HEAD is now at aabc019 Skip VM_CALL_BLOCKISEQ for Ruby < 3.3
	"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.
	From https://github.com/ruby/typeprof
	* branch aabc019684d8b4a1ed66c2a1ca48da7bbb18dcc0 -> FETCH_HEAD
	HEAD is now at aabc019 Skip VM_CALL_BLOCKISEQ for Ruby < 3.3
	"make yes-btest TESTOPTS='-q -j4'" exit with 0.

	"make yes-test-basic TESTS='-j4'" exit with 0.
	make yes-test-all TESTOPTS='--stderr-on-failure' TESTS='-j4'
	$$$ #<Timeout::Error: execution expired>
	### enter analyzing mode for stuck processes
	$$$ ps jx
	PPID PID PGID SID TTY TPGID STAT UID TIME COMMAND
	11 12 12 12 ? -1 Ss 1001 0:00 sh build-loop.sh trunk-gc-asserts --incremental --process-num=4
	1 1111922 12 12 ? -1 Sl 1001 0:00 /tmp/ruby/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:45021
	1 1133200 12 12 ? -1 Sl 1001 0:00 /tmp/ruby/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:35229
	1 1261812 12 12 ? -1 Sl 1001 0:00 /tmp/ruby/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:39967
	1 1284301 12 12 ? -1 Sl 1001 0:00 /tmp/ruby/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:35659
	12 1290239 12 12 ? -1 Sl 1001 0:00 ruby ./br.rb build_report trunk-gc-asserts --incremental --process-num=4
	1290239 1290242 12 12 ? -1 S 1001 0:00 sh -c ruby /home/ko1/build-ruby/build-ruby.rb --target_name=trunk-gc-asserts --logfile=/home/ko1/ruby/logs/brlog.trunk-gc-asserts.20230721-105101 --root_dir=/tmp/ruby --timeout=21600 --build_opts='DEFS="-DRGENGC_CHECK_MODE=2"' --add-env=RUBY_TEST_SUBPROCESS_TIMEOUT_SCALE=30 --incremental --process-num=4
	1290242 1290243 12 12 ? -1 Sl 1001 0:00 ruby /home/ko1/build-ruby/build-ruby.rb --target_name=trunk-gc-asserts --logfile=/home/ko1/ruby/logs/brlog.trunk-gc-asserts.20230721-105101 --root_dir=/tmp/ruby --timeout=21600 --build_opts=DEFS="-DRGENGC_CHECK_MODE=2" --add-env=RUBY_TEST_SUBPROCESS_TIMEOUT_SCALE=30 --incremental --process-num=4
	1290243 1294253 12 12 ? -1 Z 1001 0:00 [sh] <defunct>
	1 1296972 12 12 ? -1 Sl 1001 0:00 /tmp/ruby/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:35149
	1290243 1301798 12 12 ? -1 R 1001 0:00 ps jx
	{11=>[12], 1=>[1111922, 1133200, 1261812, 1284301, 1296972], 12=>[1290239], 1290239=>[1290242], 1290242=>[1290243], 1290243=>[1294253, 1301798]}
	$ timeout 60 gdb -p 1294253 -x /home/ko1/build-ruby/gdbscript -batch -quiet 2> /dev/null
	>>> Threads
	No threads.
	>>> Machine level backtrace
	>>> Dump Ruby level backtrace (if possible)
	$ timeout 60 gdb -p 1301798 -x /home/ko1/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>