TruffleRuby hang in CI

[eregon]

TruffleRuby is hanging in CI, I'm investigating.

Originally posted by @tisba in #408 (comment)

[eregon]

I tried with both 33.0.1 and 34.0.1 and the issue seems the same, it always hangs locally for me with:

$ MT_CPU=1 be rake test      
Run options: --seed 22074

# Running:

..........S..S.......S.........S.S.S......S.....S.S.S.S..S.SS.SS.........All Thread and Fiber backtraces:
#<Fiber:0x7318 root (resumed)> of #<Thread:0x7328 /home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest/parallel.rb:28 sleep>
/home/eregon/.rubies/truffleruby+graalvm-34.0.1/lib/truffle/thread.rb:37:in 'Queue#pop'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest/parallel.rb:30:in 'block (2 levels) in Minitest::Parallel::Executor#start'

#<Fiber:0x7348 root (resumed)> of #<Thread:0x7358 Ruby-reference-processor sleep>

#<Fiber:0x7378 root (resumed)> of #<Thread:0x7388 @active_support_execution_state={time_zone: #<ActiveSupport::TimeZone:0x73a8 @name="UTC", @utc_offset=nil, @tzinfo=#<TZInfo::DataTimezone: Etc/UTC>>} main run>
<internal:core> core/truffle/debug.rb:16:in 'Truffle::Debug.show_backtraces'
<internal:core> core/main.rb:75:in 'block (2 levels) in <top (required)>'
<internal:core> core/truffle/exception_operations.rb:33:in 'Truffle::ExceptionOperations.circular_cause?'
<internal:core> core/kernel.rb:708:in 'Kernel#raise'
<internal:core> core/truffle/polyglot.rb:324:in 'Polyglot::ExceptionTrait#marshal_dump'
<internal:core> core/marshal.rb:1338:in 'Marshal::State#serialize_user_marshal'
<internal:core> core/marshal.rb:1156:in 'Marshal::State#serialize'
<internal:core> core/marshal.rb:135:in 'Exception#__marshal__'
<internal:core> core/marshal.rb:1160:in 'Marshal::State#serialize'
<internal:core> core/marshal.rb:1502:in 'Marshal.dump'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest/test.rb:200:in 'Minitest::Test#sanitize_exception'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest/test.rb:196:in 'Minitest::Test#capture_exceptions'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest/test.rb:89:in 'block in Minitest::Test#run'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:368:in 'Minitest::Runnable#time_it'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest/test.rb:88:in 'Minitest::Test#run'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:1208:in 'Minitest.run_one_method'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:447:in 'Minitest::Runnable.run_one_method'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:434:in 'block (2 levels) in Minitest::Runnable.run'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:430:in 'Array#each'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:430:in 'block in Minitest::Runnable.run'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:472:in 'Minitest::Runnable.on_signal'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:459:in 'Minitest::Runnable.with_info_handler'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:429:in 'Minitest::Runnable.run'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:332:in 'block in Minitest.__run'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:332:in 'Array#map'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:332:in 'Minitest.__run'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:288:in 'Minitest.run'
/home/eregon/code/mini_racer/vendor/bundle/truffleruby/34.0.1.1/gems/minitest-5.25.4/lib/minitest.rb:86:in 'block in Minitest.autorun'

This backtrace is obtained by sending SIGARLM to the process, to make it dump Ruby backtraces.

There are two parts to this:

• Truffle::ExceptionOperations.circular_cause? seems to loop indefinitely, hence the hang.
• Minitest tries to Marshal an exception in Minitest::Test#sanitize_exception, this has already caused issues in the past, I think we should avoid that in Minitest if possible, because in general it's not possible to faithfully marshal all exceptions.

[eregon]

<internal:core> core/truffle/polyglot.rb:324:in 'Polyglot::ExceptionTrait#marshal_dump'
is
https://github.com/truffleruby/truffleruby/blob/graal-34.0.1/src/main/ruby/truffleruby/core/truffle/polyglot.rb#L323-L325

So Minitest is trying to Marshal a Polyglot::ForeignException, which can't work.

[eregon]

If I comment out https://github.com/minitest/minitest/blob/f6180b07ea6e8504a71d220246da0875f392c51c/lib/minitest/test.rb#L197
we see the real error and there is no hang:

$ MT_CPU=1 be rake test
Run options: --seed 21205

# Running:

.S..SS.SE.......S.S.S.........S......S..S......SS.S..S.......S.....S.S....S....SS.....SS.S.....S......

Finished in 8.223836s, 12.4030 runs/s, 18.2397 assertions/s.

  1) Error:
MiniRacerTest#test_binary_returns_uint8array:
NoMethodError: undefined method 'bytes' for an instance of Array
    test/mini_racer_test.rb:1230:in 'block in MiniRacerTest#test_binary_returns_uint8array'
    lib/mini_racer/shared.rb:197:in 'block in MiniRacer::Context#attach'
    lib/mini_racer/truffleruby.rb:17:in 'block in MiniRacer::Context::ExternalFunction#notify_v8'
    <internal:core> core/truffle/polyglot.rb:45:in 'Polyglot::InnerContext#eval'
    (mini_racer):1:in 'MiniRacer::Context#eval_in_context'
    lib/mini_racer/truffleruby.rb:147:in 'block in MiniRacer::Context#eval_unsafe'
    lib/mini_racer/truffleruby.rb:199:in 'MiniRacer::Context#translate'
    lib/mini_racer/truffleruby.rb:146:in 'MiniRacer::Context#eval_unsafe'
    lib/mini_racer/shared.rb:152:in 'block (2 levels) in MiniRacer::Context#eval'
    lib/mini_racer/shared.rb:273:in 'MiniRacer::Context#timeout'
    lib/mini_racer/shared.rb:151:in 'block in MiniRacer::Context#eval'
    lib/mini_racer/shared.rb:149:in 'Mutex#synchronize'
    lib/mini_racer/shared.rb:149:in 'MiniRacer::Context#eval'
    test/mini_racer_test.rb:1233:in 'MiniRacerTest#test_binary_returns_uint8array'

102 runs, 150 assertions, 0 failures, 1 errors, 24 skips

[eregon]

Running it as a standalone repro, because Minitest hides causes (minitest/minitest#727):

require 'mini_racer'

context = MiniRacer::Context.new
context.attach("add_one", ->(data) {
  MiniRacer::Binary.new(data.bytes.map { _1 + 1 }.pack("C*"))
})

result = context.eval <<~JS
var output = add_one(new Uint8Array([0, 1, 2, 3]));
(output instanceof Uint8Array) && Array.from(output).join(",") === "1,2,3,4";
JS

p result

$ ruby -Ilib repro.rb   
[ruby] WARNING StackOverflowError
Error while formatting Ruby exception:
<internal:core> core/truffle/polyglot.rb:264:in 'Polyglot::ArrayTrait#reverse': stack level too deep (SystemStackError)
	from com.oracle.truffle.runtime.OptimizedCallTarget.doInvoke(OptimizedCallTarget.java:662)
	from <internal:core> core/truffle/polyglot.rb:300:in 'Polyglot::ExceptionTrait#backtrace_locations'
	from <internal:core> core/truffle/polyglot.rb:320:in 'Polyglot::ExceptionTrait#backtrace'
	from <internal:core> core/truffle/exception_operations.rb:306:in 'Truffle::ExceptionOperations.append_causes'
	from <internal:core> core/truffle/exception_operations.rb:312:in 'Truffle::ExceptionOperations.append_causes'
	from <internal:core> core/truffle/exception_operations.rb:312:in 'Truffle::ExceptionOperations.append_causes'
	from <internal:core> core/truffle/exception_operations.rb:312:in 'Truffle::ExceptionOperations.append_causes'
	from <internal:core> core/truffle/exception_operations.rb:312:in 'Truffle::ExceptionOperations.append_causes'
...
	from <internal:core> core/truffle/exception_operations.rb:312:in 'Truffle::ExceptionOperations.append_causes'
	from <internal:core> core/truffle/exception_operations.rb:312:in 'Truffle::ExceptionOperations.append_causes'
	from <internal:core> core/truffle/exception_operations.rb:259:in 'Truffle::ExceptionOperations.full_message'
	from <internal:core> core/truffle/exception_operations.rb:354:in 'Truffle::ExceptionOperations.get_formatted_backtrace'
Original Ruby exception:
repro.rb:5:in 'block in <main>': undefined method 'bytes' for an instance of Array (NoMethodError)
	from /home/eregon/code/mini_racer/lib/mini_racer/shared.rb:197:in 'block in MiniRacer::Context#attach'
	from /home/eregon/code/mini_racer/lib/mini_racer/truffleruby.rb:17:in 'block in MiniRacer::Context::ExternalFunction#notify_v8'
	from <internal:core> core/truffle/polyglot.rb:45:in 'Polyglot::InnerContext#eval'
	from (mini_racer):1:in 'MiniRacer::Context#eval_in_context'
	from /home/eregon/code/mini_racer/lib/mini_racer/truffleruby.rb:147:in 'block in MiniRacer::Context#eval_unsafe'
	from /home/eregon/code/mini_racer/lib/mini_racer/truffleruby.rb:199:in 'MiniRacer::Context#translate'
	from /home/eregon/code/mini_racer/lib/mini_racer/truffleruby.rb:146:in 'MiniRacer::Context#eval_unsafe'
	from /home/eregon/code/mini_racer/lib/mini_racer/shared.rb:152:in 'block (2 levels) in MiniRacer::Context#eval'
	from /home/eregon/code/mini_racer/lib/mini_racer/shared.rb:273:in 'MiniRacer::Context#timeout'
	from /home/eregon/code/mini_racer/lib/mini_racer/shared.rb:151:in 'block in MiniRacer::Context#eval'
	from /home/eregon/code/mini_racer/lib/mini_racer/shared.rb:149:in 'Mutex#synchronize'
	from /home/eregon/code/mini_racer/lib/mini_racer/shared.rb:149:in 'MiniRacer::Context#eval'
	from repro.rb:8:in '<main>'