From: Rodrigo Rosenfeld Rosas Date: 2014-01-18T21:31:28-02:00 Subject: [ruby-core:59861] Re: About unmarshallable DRb objects life-time This is a multi-part message in MIME format. --------------030704000004080603070306 Content-Type: text/plain; charset=UTF-8; format=flowed Content-Transfer-Encoding: 8bit Em 17-01-2014 12:49, Rodrigo Rosenfeld Rosas escreveu: > Em 17-01-2014 10:22, Rodrigo Rosenfeld Rosas escreveu: >> Em 16-01-2014 19:43, Eric Hodel escreveu: >>> On 16 Jan 2014, at 02:15, Rodrigo Rosenfeld Rosas >>> wrote: >>>>> The above matters especially so for objects that you extend with >>>>> DRbUndumped. This means you must keep the object alive where you >>>>> create it or the GC will throw it away when no references remain. >>>> Thank you, this confirms my suspicion. Unfortunately it's not >>>> feasible to create a generic proxy to the JVM from MRI through DRb >>>> and JRuby as I first thought it would be. It would be the case if >>>> DRb was responsible for translating any references in the DRb >>>> client-side as another local reference in the server-side so that >>>> those objects wouldn't be collected by GC. In that case it should >>>> also be responsible for removing the local references as the >>>> counterpart in the DRb client goes away. >>>> >>>> But maybe this is too hard to implement, so I'll give up on the >>>> generic MRI-JVM bridge by using DRb. I'll try to update my article >>>> soon to explain what I found and stop recommending that approach. >>> As I noted in my email (not quoted in this reply) you can use id >>> conversion to provide a way to keep local references alive. DRb >>> doesn���t provide a generic way to do this as there is not a >>> one-size-fits-all solution to this problem. >>> >>> You could try an id converter that combined an LRU of a reasonable >>> size along with the ability to recreate local objects for items that >>> fall off the LRU. >> >> I guess the problem is that I didn't quite understand what you meant >> by this id_conv thing even after looking at the examples you pointed >> me to. Are there any comprehensive documentation about this feature? >> >> the problem is that the DRb client is creating instances in the >> server-side that are not hold themselves in the server-side but only >> referenced in the client-side using some kind of a proxy to the >> object that is only present in the server-side. Even if I could >> somehow mark those objects transparently to remain alive, I'd still >> have to figure out a way to detect when no references exist to it any >> longer in the client-side so that I could free those objects in the >> server-side as well or the server-side will leak. >> >> That's why I think this must be implemented in the DRb specification >> itself or it wouldn't be feasible to implement in away that would be >> transparent for the user. My real goal is for the user in the >> client-side to have a feeling that he's programming directly in the >> server-side, just using DRb as a proxy to allow him to use features >> only available in the server-side. That includes creating temporary >> objects that should be freed once no references exist to them in the >> client-side. >> >> If I'm missing something, would you mind to explain it to me in a >> more comprehensive way? > > I changed my approach to move all logic to the DRb server to export > data to Excel, but now I'm facing a weird problem I have no idea what > could be causing (in production only, it worked in my development > machine). > > The exported service has a method like this: > > def export_search_results_to_excel(data, stream) > ExcelSearchResultsExporter.new(data).export_to stream > end > > In the Rails controller, there's something like this: > > class SearchController < ApplicationController > include ActionController::Live # for streaming support > ... > def export_results_to_excel > ... > response.headers['Content-Type'] = 'application/vnd.ms-excel' > response.headers['Content-Disposition'] = 'attachment; > filename="search-results.xls"' > ExcelExporterService.instance.export_search_results data, > response.stream > end > end > > where ExcelExporterService is something like: > > require 'drb_setup' # require 'drb/drb'; DRb.start_service > require 'singleton' > require 'application_settings' > > class ExcelExporterService > include Singleton > > def initialize > @service = DRbObject.new_with_uri > ApplicationSettings.instance.java_bridge_uri > end > > def export_search_results(data, stream) > stream.extend DRb::DRbUndumped > @service.export_search_results_to_excel data, stream > stream.close > end > end > > Finally, in the server-side (JRuby), the implementation of export_to > looks like: > > require 'java' > import org.jruby.util.IOOutputStream > import java.io.OutputStream > ... > # with streaming support: out must implement at least write and close > def export_to(out) > out = IOOutputStream.new(out) unless out.is_a? OutputStream # THIS > IS LINE 37 > @sheet = @workbook.create_sheet SPREADSHEET_NAME > render_sheet > @workbook.write out > end > > But then, in the staging server, I get errors like this: > > I, [2014-01-17T14:38:42.108974 #28820] INFO -- : Completed 500 > Internal Server Error in 378ms > F, [2014-01-17T14:38:42.113094 #28820] FATAL -- : > NoMethodError (undefined method `call_on_error' for > #): > /var/www/apps/shared/bundle/ruby/2.0.0/gems/actionpack-4.0.2/lib/action_controller/metal/live.rb:136:in > `rescue in block in process' > /var/www/apps/shared/bundle/ruby/2.0.0/gems/actionpack-4.0.2/lib/action_controller/metal/live.rb:145:in > `block in process' > > > F, [2014-01-17T14:38:42.113319 #28820] FATAL -- : > RangeError (0x003faa115f8e94 is recycled object): > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:369:in > `_id2ref' > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:369:in > `to_obj' > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1446:in > `to_obj' > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1748:in > `to_obj' > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:618:in > `recv_request' > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:926:in > `recv_request' > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1563:in > `init_with_client' > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1575:in > `setup_message' > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1527:in > `perform' > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1626:in > `block (2 levels) in main_loop' > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1622:in > `loop' > (druby://ip-10-232-28-189.ec2.internal:42014) > /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1622:in > `block in main_loop' > (druby://localhost:31777) > /home/myuser/.rbenv/versions/jruby-1.7.9/lib/ruby/1.9/drb/drb.rb:1115:in > `respond_to?' > (druby://localhost:31777) > /var/www/apps/experimental/java_bridge/releases/20140117135423/lib/excel_search_results_exporter.rb:37:in > `export_to' > > Searching the web I found this explanation: > > http://627nm.blogspot.com.br/2009/04/drb-and-rangeerror.html > > But I don't think it makes sense for my case since there's no reason > for any object to be recycled in this case, right? We could reproduce the issue in another developer's VM. After digging a lot in the source of ActionController, we could find out that in my computer response.stream was an instance of ActionController::Live::Buffer, while in the other developer's VM it was ActionDispatch::Response::Buffer. In the end we noticed that it worked when he accessed the web server directly, but yield to errors when accessing through nginx. I sent him my nginx settings and we found out that we were missing a settting on nginx to enable streaming (by using HTTP 1.1) and that ActionController seemed to detect that and switch the response to ActionDispatch::Response instead of ActionController::Live::Response. As a result, I guess after the DRb server sent the Excel header, there wouldn't be anything else in the buffer and the non-live implementation would then close the connection after sending those 512 bytes as the exported Excel spreadsheet. After that, there's a chance the old response.stream will be collected while it's still being written to it in the DRb server, thus causing errors there. But after we fixed the nginx settings in the server, it still raised errors apparently related to collected objects but by then it was already too late and we decided to continue the investigation next week after fixing some other more urgent issues reported on Friday. The only reason I see for such errors to occur is for the connection being closed before completing the output for some reason, so that the stream object we send to the DRb server (through an DRbUndumped proxy) is no longer available when Apache POI tries to write to it... I'll post here the reasons if/when we find what's causing that in our servers, but debugging in the server will be a painful experience... If we can't find the reason after a day or so, we'll probably change our approach and use a separate web server instead of DRb for handling those requests... If you have any idea that might help us with debugging what's happening we would certainly appreciate. But one thing I was worried about is that I found something like this on the Live implementation: class Buffer < ActionDispatch::Response::Buffer #:nodoc: #... def write(string) #... super # calls @buf.push string end def each while str = @buf.pop yield str end end def close super @buf.push nil end end As far as I understand @buf is an array by default. It comes from the Response's "body" param in the initializer that is defined as: def initialize(status = 200, header = {}, body = []) ... if that's true, I'm worried if this code is thread-safe as I suspect you can't safely call @buf.pop and @buf.push concurrently with @buf being a regular Array ([]). I intend to put a mutex around each of those methods (write/each/close) and test it in the server just to be sure... Wish me luck when I'm back to the investigation of this issue :) Best, Rodrigo. --------------030704000004080603070306 Content-Type: text/html; charset=UTF-8 Content-Transfer-Encoding: 8bit
Em 17-01-2014 12:49, Rodrigo Rosenfeld Rosas escreveu:
Em 17-01-2014 10:22, Rodrigo Rosenfeld Rosas escreveu:
Em 16-01-2014 19:43, Eric Hodel escreveu:
On 16 Jan 2014, at 02:15, Rodrigo Rosenfeld Rosas <rr.rosas@gmail.com> wrote:
The above matters especially so for objects that you extend with DRbUndumped.�� This means you must keep the object alive where you create it or the GC will throw it away when no references remain.
Thank you, this confirms my suspicion. Unfortunately it's not feasible to create a generic proxy to the JVM from MRI through DRb and JRuby as I first thought it would be. It would be the case if DRb was responsible for translating any references in the DRb client-side as another local reference in the server-side so that those objects wouldn't be collected by GC. In that case it should also be responsible for removing the local references as the counterpart in the DRb client goes away.

But maybe this is too hard to implement, so I'll give up on the generic MRI-JVM bridge by using DRb. I'll try to update my article soon to explain what I found and stop recommending that approach.
As I noted in my email (not quoted in this reply) you can use id conversion to provide a way to keep local references alive.�� DRb doesn���t provide a generic way to do this as there is not a one-size-fits-all solution to this problem.

You could try an id converter that combined an LRU of a reasonable size along with the ability to recreate local objects for items that fall off the LRU.

I guess the problem is that I didn't quite understand what you meant by this id_conv thing even after looking at the examples you pointed me to. Are there any comprehensive documentation about this feature?

the problem is that the DRb client is creating instances in the server-side that are not hold themselves in the server-side but only referenced in the client-side using some kind of a proxy to the object that is only present in the server-side. Even if I could somehow mark those objects transparently to remain alive, I'd still have to figure out a way to detect when no references exist to it any longer in the client-side so that I could free those objects in the server-side as well or the server-side will leak.

That's why I think this must be implemented in the DRb specification itself or it wouldn't be feasible to implement in away that would be transparent for the user. My real goal is for the user in the client-side to have a feeling that he's programming directly in the server-side, just using DRb as a proxy to allow him to use features only available in the server-side. That includes creating temporary objects that should be freed once no references exist to them in the client-side.

If I'm missing something, would you mind to explain it to me in a more comprehensive way?

I changed my approach to move all logic to the DRb server to export data to Excel, but now I'm facing a weird problem I have no idea what could be causing (in production only, it worked in my development machine).

The exported service has a method like this:

�� def export_search_results_to_excel(data, stream)
������ ExcelSearchResultsExporter.new(data).export_to stream
�� end

In the Rails controller, there's something like this:

class SearchController < ApplicationController
�� include ActionController::Live # for streaming support
�� ...
�� def export_results_to_excel
������ ...
������ response.headers['Content-Type'] = 'application/vnd.ms-excel'
������ response.headers['Content-Disposition'] = 'attachment; filename="search-results.xls"'
������ ExcelExporterService.instance.export_search_results data, response.stream
�� end
end

where ExcelExporterService is something like:

require 'drb_setup' # require 'drb/drb'; DRb.start_service
require 'singleton'
require 'application_settings'

class ExcelExporterService
�� include Singleton

�� def initialize
������ @service = DRbObject.new_with_uri ApplicationSettings.instance.java_bridge_uri
�� end

�� def export_search_results(data, stream)
������ stream.extend DRb::DRbUndumped
������ @service.export_search_results_to_excel data, stream
������ stream.close
�� end
end

Finally, in the server-side (JRuby), the implementation of export_to looks like:

require 'java'
import org.jruby.util.IOOutputStream
import java.io.OutputStream
...
�� # with streaming support: out must implement at least write and close
�� def export_to(out)
������ out = IOOutputStream.new(out) unless out.is_a? OutputStream # THIS IS LINE 37
������ @sheet = @workbook.create_sheet SPREADSHEET_NAME
������ render_sheet
������ @workbook.write out
�� end

But then, in the staging server, I get errors like this:

I, [2014-01-17T14:38:42.108974 #28820]�� INFO -- : Completed 500 Internal Server Error in 378ms
F, [2014-01-17T14:38:42.113094 #28820] FATAL -- :
NoMethodError (undefined method `call_on_error' for #<ActionDispatch::Response::Buffer:0x007f5422bf1d28>):
�� /var/www/apps/shared/bundle/ruby/2.0.0/gems/actionpack-4.0.2/lib/action_controller/metal/live.rb:136:in `rescue in block in process'
�� /var/www/apps/shared/bundle/ruby/2.0.0/gems/actionpack-4.0.2/lib/action_controller/metal/live.rb:145:in `block in process'


F, [2014-01-17T14:38:42.113319 #28820] FATAL -- :
RangeError (0x003faa115f8e94 is recycled object):
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:369:in `_id2ref'
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:369:in `to_obj'
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1446:in `to_obj'
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1748:in `to_obj'
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:618:in `recv_request'
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:926:in `recv_request'
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1563:in `init_with_client'
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1575:in `setup_message'
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1527:in `perform'
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1626:in `block (2 levels) in main_loop'
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1622:in `loop'
�� (druby://ip-10-232-28-189.ec2.internal:42014) /home/myuser/.rbenv/versions/2.0.0-p353/lib/ruby/2.0.0/drb/drb.rb:1622:in `block in main_loop'
�� (druby://localhost:31777) /home/myuser/.rbenv/versions/jruby-1.7.9/lib/ruby/1.9/drb/drb.rb:1115:in `respond_to?'
�� (druby://localhost:31777) /var/www/apps/experimental/java_bridge/releases/20140117135423/lib/excel_search_results_exporter.rb:37:in `export_to'

Searching the web I found this explanation:

http://627nm.blogspot.com.br/2009/04/drb-and-rangeerror.html

But I don't think it makes sense for my case since there's no reason for any object to be recycled in this case, right?

We could reproduce the issue in another developer's VM. After digging a lot in the source of ActionController, we could find out that in my computer response.stream was an instance of ActionController::Live::Buffer, while in the other developer's VM it was ActionDispatch::Response::Buffer. In the end we noticed that it worked when he accessed the web server directly, but yield to errors when accessing through nginx. I sent him my nginx settings and we found out that we were missing a settting on nginx to enable streaming (by using HTTP 1.1) and that ActionController seemed to detect that and switch the response to ActionDispatch::Response instead of ActionController::Live::Response.

As a result, I guess after the DRb server sent the Excel header, there wouldn't be anything else in the buffer and the non-live implementation would then close the connection after sending those 512 bytes as the exported Excel spreadsheet. After that, there's a chance the old response.stream will be collected while it's still being written to it in the DRb server, thus causing errors there.

But after we fixed the nginx settings in the server, it still raised errors apparently related to collected objects but by then it was already too late and we decided to continue the investigation next week after fixing some other more urgent issues reported on Friday. The only reason I see for such errors to occur is for the connection being closed before completing the output for some reason, so that the stream object we send to the DRb server (through an DRbUndumped proxy) is no longer available when Apache POI tries to write to it...

I'll post here the reasons if/when we find what's causing that in our servers, but debugging in the server will be a painful experience... If we can't find the reason after a day or so, we'll probably change our approach and use a separate web server instead of DRb for handling those requests...

If you have any idea that might help us with debugging what's happening we would certainly appreciate.

But one thing I was worried about is that I found something like this on the Live implementation:

class Buffer < ActionDispatch::Response::Buffer #:nodoc:
#...
���������� def write(string)
������ ������ #...
�������������� super # calls @buf.push string
���������� end

���������� def each
�������������� while str = @buf.pop
������������������ yield str
�������������� end
���������� end

���������� def close
�������������� super
�������������� @buf.push nil
���������� end
end

As far as I understand @buf is an array by default. It comes from the Response's "body" param in the initializer that is defined as:

������ def initialize(status = 200, header = {}, body = [])
...

if that's true, I'm worried if this code is thread-safe as I suspect you can't safely call @buf.pop and @buf.push concurrently with @buf being a regular Array ([]). I intend to put a mutex around each of those methods (write/each/close) and test it in the server just to be sure...

Wish me luck when I'm back to the investigation of this issue :)

Best,
Rodrigo.

--------------030704000004080603070306--