jRuby StackOverflowError in versions above 2.3.14

[erikogan]

I have an integration test that started throwing a StackOverflowError in jRuby when I tried to upgrade from 2.3.14 to 2.3.19. I tested the versions between and discovered that it’s caused by a change included in 2.3.15.

Because the StackOverflowError blows away the actual calling stack, it’s hard for me to speculate on what might be causing it, but I am happy to dig into it if needed.

If you have trouble reproducing it, I could probably git bisect and get it down to a particular commit.

I’m running:
jruby-9.1.2.0
rspec-3.5.0
(and Rails-5.0, but I don’t believe that’s relevant)
I can provide the Gemfile.lock if that would help.

The (slightly simplified) spec looks like this:

RSpec.describe MyController, type: :controller do
  let(:s3) { Aws::S3::Resource.new }
  let(:s3path) { 'a/random/s3/test_file.csv' }

  before do
    Aws.config[:s3] = {
      stub_responses: {
        list_objects: { contents: [{ key: s3path }] },
        get_object: { body: File.read(Rails.root.join('spec/fixtures/signature_data.txt')) },
        # TODO: Figure out if there is a way to do this
        put_object: { }
      }
    }

    allow(RedshiftExporter::CONNECTION_POOL).to receive(:with)

    # TODO: Figure out the prescribed way to mock put_object and test its body
    allow(Aws::S3::Resource).to receive(:new).and_return(s3)
    s3client = s3.instance_variable_get('@client')
    # Call the original method
    original_put_object = s3client.method(:put_object)
    allow(s3client).to receive(:put_object) do |obj, &block|
      @csv_file = StringIO.new(obj[:body].read, 'r:UTF-16le')
      obj[:body].rewind # probably unnecessary
      original_put_object.call(obj, &block)
    end
  end

  subject do
    @csv_file.read(3) # Remove BOM
    CSV.new(@csv_file, col_sep: "\t")
  end

   it 'should have headers' do
    Sidekiq::Testing.inline! do
      post :create, params: params, body: body.to_json
    end

    expect(subject.shift).to eq headers
  end

end

[erikogan]

It just occurred to me that calling the original_put_object method might be at least partially to blame for this. I am going to try refactoring that out.

[erikogan]

Strangely, commenting out that line (and replacing it with an empty hash return) causes a similar error in 2.3.14, not the NoMethodError on nil I expected.

Something very strange is afoot.

[awood45]

Taking a look - have you tried something like byebug to find the line in your code where things start to loop?

[trevorrowe]

Calling the original method would definitely cause a stack overflow error, as it would be recursive. Looking at your test, it appears that you are trying to assert something about the value being sent to Aws::S3::Client#put_object, is that correct?

It sounds like you need to record requests sent to the client so you can assert about the values they receive. We do this in some of our integration tests. A simple way to do this is by registering a handler on the client.

requests = []
client = Aws::S3::Client.new(stub_responses:true)
client.handle do |request| # register a handler in the request handler stack
  requests << request
  @handler.call(request)
end

# now make some requests
client.put_object(bucket:'aws-sdk', key:'key', body:'Hello World!')

# now inspect the recorded requests
puts requests[0].operation_name #=> put_object
puts requests[0].params[:body] #=> Hello World!

Is this what you are looking for?

[erikogan]

@trevorrowe Yup, this is an integration test.

That looks like a much cleaner way to assert that the given operation is called with the expected arguments and extract arguments for testing. I’ll try refactoring that way and see what happens.

[erikogan]

Interesting. I tried to add requests to a RSpec memoized value, and I got the StackOverflowError again. I think there’s a strange interaction going on between aws-sdk & RSpec. I’ll investigate further tomorrow morning.

[erikogan]

I figured out a workaround for that particular problem so I probably won’t look at it tomorrow morning. But it intrigues me so I may poke at it in the future.

[erikogan]

I just tried to upgrade to aws-sdk 2.4.0 (and RSpec 3.5.1, but probably not relevant), and I am still getting StackOverflowError errors on the refactored specs. I’ll dig into it a bit and post the updated specs here if I don’t discover something obvious.

[erikogan]

The (slightly simplified) spec now looks like this:

RSpec.describe MyController, type: :controller do
  let(:s3) { Aws::S3::Resource.new }
  let(:s3path) { 'a/random/s3/test_file.csv' }

  before do
    Aws.config[:s3] = {
      stub_responses: {
        list_objects: { contents: [{ key: s3path }] },
        get_object: { body: File.read(Rails.root.join('spec/fixtures/signature_data.txt')) },
      }
    }

    allow(RedshiftExporter::CONNECTION_POOL).to receive(:with)

    allow(Aws::S3::Resource).to receive(:new).and_return(s3)
    s3client = s3.instance_variable_get('@client')

    # There is a very strange interaction between aws-sdk & RSpec memoized
    # values that causes a StackOverflowError when putting SDK values into
    # memoized data structures. 
    scoped_file_data = {}
    @file_data = scoped_file_data

    s3client.handle do |request| # register a handler in the request handler stack
      if request.operation_name.to_s == 'put_object'
        scoped_file_data[:csv_file] = StringIO.new(request.params[:body], 'r:UTF-16le')
      end
      @handler.call(request)
    end
  end

  subject do
    @csv_file.read(3) # Remove BOM
    CSV.new(@csv_file, col_sep: "\t")
  end

   it 'should have headers' do
    Sidekiq::Testing.inline! do
      post :create, params: params, body: body.to_json
    end

    expect(subject.shift).to eq headers
  end

end

I just confirmed that rolling back to 2.3.14 resolves the problem. I am going to see if I can step through and track where the infinite loop happens.

[erikogan]

Eureka! It is not clear to me why this causes jRuby to overflow its stack, but the problem is that I am passing put_object a body that is an unlinked Tempfile object.

Aws::Plugins::S3Md5s::Handler.call tries to add an MD5 header to the request
Aws::Checksums.md5 correctly identifies it as a Tempfile object, calling
OpenSSL::Digest::MD5.file which calls File.open(file, 'rb').

This works fine (to my surprise) when the Tempfile still exists in the filesystem, but fails when the file has been unlinked. This appears to be because calling File.open on an existing File object tries to reopen the same file name, instead of dup’ing the underlying fd. I just tested the behavior in MRI 2.0, and acts similarly.

Attempting to reproduce that error in isolation:

tf = Tempfile.new
tf.unlink
tf.puts "hi!"
File.open(tf, "rb") {|f| f.read}

Causes a much more understandable error: TypeError: no implicit conversion of nil into String. (And commenting out the unlink causes it to work.)

This leads me to believe that something in the jRuby exception handling (or possibly RSpec’s) is what is really causing the stack to overflow.

However, I do think that aws-sdk should be able to upload data from a file descriptor that has been unlinked in the filesystem without erroring (as it was in 2.3.14).

[erikogan]

Fortunately it was a pretty easy fix. The code already exists to read from the filehandle and rewind.

[trevorrowe]

@erikogan I'm not sure I understand how the SDK would be able to reliably upload the contents of an unlinked file.

[erikogan]

@trevorrowe See the attached PR. The file can be unlinked in the filesystem, but open file descriptors continue to have access to it until they are closed. The filesystem inodes are only freed once all descriptors have been closed.

It is common practice with unix tools to unlink temporary files as soon as they are created, both for security as well as housekeeping reasons.