Encoding error with bad raise message in StringIO

[headius]

Reported via ruby/rake#619.

The failure shown in this PR and below is caused by the following sequence of events:

• An exception is raised with a multi-byte UTF-8 string forced to US-ASCII encoding.
• The exception message is written out to a StringIO by rake's trace feature.
• The exception backtrace is written out to the same StringIO, but because it now contains invalid characters the append logic raises.

The error is here (with -X+C for better Java trace context):

Error: test_display_exception_details_bad_encoding(TestRakeApplication): Java::JavaLang::RuntimeException: org.jruby.exceptions.EncodingError$CompatibilityError: (CompatibilityError) incompatible encodings: US-ASCII and UTF-8
org.jruby.ext.stringio.StringIO.catString(StringIO.java:1665)
org.jruby.ext.stringio.StringIO.stringIOWrite(StringIO.java:1721)
org.jruby.ext.stringio.StringIO.write(StringIO.java:1594)
org.jruby.ext.stringio.StringIO$INVOKER$i$write.call(StringIO$INVOKER$i$write.gen)
org.jruby.dist/org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:242)
org.jruby.dist/org.jruby.RubyIO.write(RubyIO.java:2998)
org.jruby.dist/org.jruby.RubyIO.print1(RubyIO.java:1969)
org.jruby.dist/org.jruby.RubyIO.print(RubyIO.java:1941)
org.jruby.ext.stringio.StringIO$GenericWritable.print(StringIO.java:2045)
Users.headius.work.rake.lib.rake.trace_output.️❤ def trace_on #2(/Users/headius/work/rake/lib/rake/trace_output.rb:20)
Users.headius.work.rake.lib.rake.application.️❤ def trace #55(/Users/headius/work/rake/lib/rake/application.rb:420)
Users.headius.work.rake.lib.rake.application.️❤ def display_exception_backtrace #30(/Users/headius/work/rake/lib/rake/application.rb:279)
Users.headius.work.rake.lib.rake.application.️❤ def display_exception_details #25(/Users/headius/work/rake/lib/rake/application.rb:246)
Users.headius.work.rake.lib.rake.application.️❤ def display_error_message #24(/Users/headius/work/rake/lib/rake/application.rb:236)
Users.headius.work.rake.lib.rake.application.️❤ def display_error_message #24 **(/Users/headius/work/rake/lib/rake/application.rb:234)
org.jruby.dist/org.jruby.internal.runtime.methods.CompiledIRMethod.call(CompiledIRMethod.java:139)
org.jruby.dist/org.jruby.ir.targets.indy.InvokeSite.performIndirectCall(InvokeSite.java:860)
org.jruby.dist/org.jruby.ir.targets.indy.InvokeSite.invoke(InvokeSite.java:785)
Users.headius.work.rake.test.test_rake_application.️❤ {} test_display_exception_details_bad_encoding #13(/Users/headius/work/rake/test/test_rake_application.rb:97)

The test is here:

https://github.com/ruby/rake/blob/24a583e976d406b7b164e5cf7206cba44524887b/test/test_rake_application.rb#L88-L102

It seems we are not handling the badly-encoded string properly, either going into the exception or coming out of it. Possibly we are also not handling the case where StringIO receives a badly-encoded string followed by a well-formed string.

[headius]

Seems related to this change: ruby/stringio@f75f90c

The encoding check here doesn't fail but it ends up writing MBC into the StringIO and switching it to US-ASCII. That causes a subsequent write to blow up, because the bytes aren't valid anymore.

[headius]

Reduced:

begin
  raise
rescue => ex
end

require 'stringio'
err = StringIO.new
err.print("El Niño is coming!".dup.force_encoding("US-ASCII"))
err.print(ex.backtrace[0])

[headius]

This is not directly a fix but it eliminates the internal Java RuntimeException:

diff --git a/ext/java/org/jruby/ext/stringio/StringIO.java b/ext/java/org/jruby/ext/stringio/StringIO.java
index 2eb0588..83bd60f 100644
--- a/ext/java/org/jruby/ext/stringio/StringIO.java
+++ b/ext/java/org/jruby/ext/stringio/StringIO.java
@@ -1662,7 +1662,7 @@ public class StringIO extends RubyObject implements EncodingCapable, DataType {
         try {
             RubyString unused = (RubyString) CAT_WITH_CODE_RANGE.invokeExact(myString, str);
         } catch (Throwable t) {
-            throw new RuntimeException(t);
+            Helpers.throwException(t);
         }
     }

There's some very sensitive combination of encoding, code range, and valid or invalid content at play here. If CRuby runs the repro above and calls the final print with a MBC string, it raises the same error. It seems that when the string is 7-bit ASCII it avoids the encoding incompatibility... and possibly that is a bug in CRuby.

[headius]

Ok, I'm pretty sure this is just a lucky combination of things that caused us to fall into a more strict encoding path.

This is as reduced as I can get the case, using JRuby internal APIs to force the code range to VALID:

repro_without_exception_jruby_valid.rb:

require 'jruby'
require 'stringio'

err = StringIO.new
err.print("ñ".dup.force_encoding("US-ASCII"))
str = "x"
JRuby.ref(str).setCodeRange(32)
err.print(str)

When the second print string is VALID, it causes additional encoding checks to fire in the rb_enc_str_buf_cat logic used by StringIO#write. If the string is not VALID (UNKNOWN or 7BIT) it does not follow that path and blindly adds the additional string content to the target.

In CRuby, I do not know how to force a non-MBC string to become VALID, but if we use a UTF-8 MBC string for the second print (which should be VALID), CRuby errors the same way:

repro_without_exception_with_mbc.rb:

require 'stringio'

err = StringIO.new
err.print("ñ".dup.force_encoding("US-ASCII"))
err.print("å")

Output:

$ cx 3.4 ruby blah.rb
blah.rb:5:in 'StringIO#write': incompatible character encodings: US-ASCII and UTF-8 (Encoding::CompatibilityError)
	from blah.rb:5:in 'IO::generic_writable#print'
	from blah.rb:5:in '<main>'

I can also trigger it on CRuby if there are any MBC components in the stack trace, such as by having MBC in the filename:

$ cat reprø_without_exception_mbc_filename.rb
require 'stringio'

begin
  raise
rescue => ex
end

err = StringIO.new
err.print("ñ".dup.force_encoding("US-ASCII"))
err.print(ex.backtrace.join)
$ cx 3.4 ruby reprø_without_exception_mbc_filename.rb
blåh.rb:10:in 'StringIO#write': incompatible character encodings: US-ASCII and UTF-8 (Encoding::CompatibilityError)
	from blåh.rb:10:in 'IO::generic_writable#print'
	from blåh.rb:10:in '<main>'

The "with exception" example from previous comments fails because the backtrace elements are VALID. This is because when we construct the Ruby backtrace, we turn Java exception stack trace strings into Ruby strings as VALID UTF-8, which then follows the VALID path (even if they might be 7-bit). The resulting string triggers the encoding checks as in the "without exception" case above.

I can "fix" this by converting Java strings into Ruby strings as either UNKNOWN or by re-scanning for code range (which makes the backtrace elements 7BIT in this case. However I think this test case in Rake probably just managed to get lucky with the right combination of encodings, bytes, and code ranges.

@hsbt @nobu I would like to discuss these findings with you when you have an opportunity. I will fix JRuby and push a new jruby-head build that resolves the failure in rake, but this is a very fragile test case that perhaps is not testing what it should be testing.

[headius]

Fixed by #8711