Skip to content

Code behavior changes after being JITted at runtime #4425

@mvdamme

Description

@mvdamme

Hi, I'm having a strange issue while upgrading an old Rails application to JRuby 9.1.6.0 (latest released version, installed using rvm).

I have a long-running excel-export that used to work without issues under 1.7 (it uses apache POI to write an Excel file).
Using 9.1.6.0, part of the code seems to be JIT-compiled after writing 52 rows to the excel file (at least, that's what I suspect). As of row 53, the code behavior changes causing some columns not to be exported any longer. If I run the export a second time, the problem occurs from the start (i.e. as of row 1).

When I disable the JIT compiler (using JRUBY_OPTS= -J-Djruby.compile.mode=OFF in .ruby-env) the problem disappears entirely, and the export works correctly for all rows and it keeps working when running it again.

Environment

  • output of jruby -v: jruby 9.1.6.0 (2.3.1) 2016-11-09 0150a76 OpenJDK 64-Bit Server VM 24.121-b00 on 1.7.0_121-b00 [linux-x86_64]
  • JRUBY_OPTS not set (at least when the problem occurs, setting it to -J-Djruby.compile.mode=OFF makes the problem disappear)
  • output of uname -a: Linux xps 3.13.0-35-generic #62~precise1-Ubuntu SMP Mon Aug 18 14:52:04 UTC 2014 x86_64 x86_64 x86_64 GNU/Linux

The application is a Rails app (being upgraded to Rails 4.2, the problem occurred under 4.2.7.1).

Problem code

To give an idea of what the code is doing, here's a shortened version (not runnable):

def self.export_payments_general(from_date, thru_date, to_export, mode = :excel, filename = nil, &block)
  workbook  = Excel::ExcelWorkbook.new
  worksheet = workbook['book1']

  # BCCA fields (name and max length)
  fields = [
    [ 'Taal', 2 ],
    [ 'Prive persoon', nil ],
    [ 'Naam', 70 ],
    [ 'Vervolg naam', 80 ],
    [ 'Straat', 40 ],
    [ 'Vervolg straat', 50 ],
    [ 'Huisnr.', 7 ],
    [ 'Busnr.', 6 ],
    [ 'Postnr.', 10 ],
    # many other fields...
  ]

  row = 0
  col = 0
  # use block to auto increment col value
  set_cell = ->(value, bold = false, max_length = nil) do
    val = value
    val = (val.to_s)[0..max_length] if max_length
    worksheet[row][col].value = val
    make_bold(worksheet[row][col]) if bold
    col += 1
  end

  ## Create header
  fields.each do |field|
    set_cell[ field.first, true ]
  end

  ## create payment list
  if to_export == :payments
    applications = ...  # code to extract correct list of applications from the database
  end

  # loop over data
  total = applications.size
  I18n.with_locale( :en ) do
    row += 1
    applications.each_with_index do |app, index|
      app = app.specialize
      person = app.person
      col = 0

      inv_data = app.invoice_data
      set_cell[ person.language.locale[0].upcase ]
      set_cell[ bool_to_string( app.invoice_to == 'person' ) ]
      set_cell[ inv_data[:name], false, fields[col].last ]
      col += 1  # name_ext
      set_cell[ inv_data[:street], false, fields[col].last ]
      col += 1  # street_ext
      set_cell[ inv_data[:number], false, fields[col].last ]
      set_cell[ inv_data[:bus], false, fields[col].last ]
      set_cell[ inv_data[:zipcode], false, fields[col].last ]
      # ... many other calls to set_cell block

      row += 1
      
      # report progress
      block.call(index+1, total) if block_given?
    end
  end

  # code to write xls file (omitted)
end

Explanation:

set_cell is a lambda that writes a value (possibly shortened to respect constraints) to the cell with coordinates [row, col] (both row and col are created before set_cell and are hence available), after which it increments col. A successive call to set_cell then writes its value to the next column.
When looping over the data, for each row col is initialized to zero, and then incremented inside set_cell. Some columns have to remain empty, so then we just increment col ourselves.

This works only for a limited number of rows when the JIT compiler is enabled. What seems to happen after JIT compilation is the following:

  • When starting the export of a new row, col is initialized to zero
  • The set_cell lambda works, correctly incrementing col (which also starts at zero), but the link between col inside the lambda and col inside the loop (which should be the same variable) seems to be lost. Successive calls to set_cell still increment their own version of col, but this doesn't affect the value of col outside the lambda (i.e. the value of col as seen in the loop doesn't change).
  • When executing col += 1 inside the main loop for the first time, col takes the value of 1 (since this version of col wasn't changed by the lamba, although it should have been). For some reason, this restores the link between both col versions, and as of that moment incrementing col inside the lambda (by calls to set_cell is correctly reflected in col as available in the loop).
  • For the export, this implies that some columns are overwritten.
  • During successive calls to set_cell, the link between both versions of col is lost and then recovered again.

So far, I haven't been able to reproduce this issue outside the context of this application.

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions