Bug #1544: rb_io_write bug? http://redmine.ruby-lang.org/issues/show/1544 Author: Brian Lopez Status: Open, Priority: Normal ruby -v: ruby 1.9.1p0 (2009-01-30 revision 21907) [i386-darwin9.6.0] I'm using rb_io_write to write (in C) to a StringIO instance (which was defined in Ruby, and passed to my C code) and noticed some strange behavior. I'm writing to the IO at the beginning of a recursively called method and under 1.9.1 it's *really* slow unless I buffer up the contents then only write to the IO once using rb_io_write. For what I'm doing it's the difference between completing in 3.3 seconds, vs 0.13 seconds. Under 1.8.6 I can write to the IO using rb_io_write in the smaller chunks (on ever recursive call) and it performs similar to the buffered write in 1.9.1. Any known reason for this?
on 30.05.2009 22:34
on 31.05.2009 22:44
Hi,
In message "Re: [ruby-core:23642] [Bug #1544] rb_io_write bug?"
on Sun, 31 May 2009 05:33:18 +0900, Brian Lopez
<redmine@ruby-lang.org> writes:
|I'm using rb_io_write to write (in C) to a StringIO instance (which was defined in Ruby, and passed to my C code) and noticed some strange behavior.
|I'm writing to the IO at the beginning of a recursively called method and under 1.9.1 it's *really* slow unless I buffer up the contents then only write to the IO once using rb_io_write. For what I'm doing it's the difference between completing in 3.3 seconds, vs 0.13 seconds.
|Under 1.8.6 I can write to the IO using rb_io_write in the smaller chunks (on ever recursive call) and it performs similar to the buffered write in 1.9.1.
1.9 does not use stdio, so there's possibility.
Can you show us the code to profile?
matz.
on 30.06.2009 01:26
Issue #1544 has been updated by Brian Lopez. Sorry, I didn't have this ticket on "watch" and didn't notice you'd replied already... Anyway, the code is in my yajl-ruby project. Specifically, if you look here: http://github.com/brianmario/yajl-ruby/blob/866e58ed553083e079ed5797eb5a6256dd6ce2d3/ext/yajl_ext.c#L74 That line is the call to rb_io_write that I was talking about. You'll notice I have it only call rb_io_write if the write buffer size is equal or surpassed the WRITE_BUFSIZE constants value (defaults to 8kb). Previously, I wasn't doing that buffer size check and just calling rb_io_write on every call of the yajl_encode_part function (which is called recursively. That's how I surfaced the issue. Again, it's performant in 1.8.6 either way (with the buffer size check or without). ---------------------------------------- http://redmine.ruby-lang.org/issues/show/1544
on 27.01.2010 02:04
Issue #1544 has been updated by Roger Pack. Can you extract a small reproducible script? -r ---------------------------------------- http://redmine.ruby-lang.org/issues/show/1544
on 09.04.2010 15:20
Issue #1544 has been updated by Yusuke Endoh. Status changed from Open to Feedback Hi, 2009/5/31 Brian Lopez <redmine@ruby-lang.org>: > I'm using rb_io_write to write (in C) to a StringIO instance (which was defined in Ruby, and passed to my C code) and noticed some strange behavior. > I'm writing to the IO at the beginning of a recursively called method and under 1.9.1 it's *really* slow unless I buffer up the contents then only write to the IO once using rb_io_write. For what I'm doing it's the difference between completing in 3.3 seconds, vs 0.13 seconds. > Under 1.8.6 I can write to the IO using rb_io_write in the smaller chunks (on ever recursive call) and it performs similar to the buffered write in 1.9.1. I failed to reproduce with RubyInline, 1.8.8dev and trunk. require "rubygems" require "inline" require "stringio" require "benchmark" class Test inline do |builder| builder.c <<-EOF VALUE test(VALUE io, VALUE str, VALUE num) { int i = NUM2INT(num);; while (i--) { rb_io_write(io, str); } return Qnil; } EOF end end str = "foobar" N = 100_000 Benchmark.bm do |bm| test = Test.new io = StringIO.new("") bm.report("1") { test.test(io, str, N) } io = StringIO.new("") bm.report("2") { test.test(io, str * N, 1) } end $ ../ruby-trunk-local/bin/ruby -v test.rb ruby 1.9.2dev (2010-04-09 trunk 27269) [i686-linux] user system total real 1 0.020000 0.000000 0.020000 ( 0.019992) 2 0.010000 0.000000 0.010000 ( 0.001042) $ ruby18 -v test.rb ruby 1.8.8dev (2010-04-08) [i686-linux] user system total real 1 0.020000 0.000000 0.020000 ( 0.020884) 2 0.000000 0.000000 0.000000 ( 0.001030) I tried various parameters of string length and loop count, but I cannot reproduce the phenomenon you said. I admit the condition will be very different from yours, though. 2009/6/30 Brian Lopez <redmine@ruby-lang.org>: > Anyway, the code is in my yajl-ruby project. Specifically, if you look here: http://github.com/brianmario/yajl-ruby/blob/866e58ed553083e079ed5797eb5a6256dd6ce2d3/ext/yajl_ext.c#L74 > That line is the call to rb_io_write that I was talking about. You'll notice I have it only call rb_io_write if the write buffer size is equal or surpassed the WRITE_BUFSIZE constants value (defaults to 8kb). > > Previously, I wasn't doing that buffer size check and just calling rb_io_write on every call of the yajl_encode_part function (which is called recursively. That's how I surfaced the issue. We are not familiar with yajl at all. Please show us the smaller code to reproduce, or at least, tell us the process to reproduce with yajl... I can't help but close this ticket unless you answer. -- Yusuke ENDOH <mame@tsg.ne.jp> ---------------------------------------- http://redmine.ruby-lang.org/issues/show/1544
on 09.04.2010 17:45
Issue #1544 has been updated by Brian Lopez. Yusuke, as mentioned in my original post the issue I was having was in 1.9 not 1.8. The line of code that was affected by the bug is http://github.com/brianmario/yajl-ruby/blob/master/ext/yajl_ext.c#L116 - I'll do my best to test this again on a newer version of 1.9.1 as my original finding of the bug was with 1.9.1p0. That being said, the code you have looks like it would trigger it just fine (but on 1.9) ---------------------------------------- http://redmine.ruby-lang.org/issues/show/1544