Project

General

Profile

Bug #1544

rb_io_write bug?

Added by brianmario (Brian Lopez) over 10 years ago. Updated about 2 months ago.

Status:
Closed
Priority:
Normal
Assignee:
-
ruby -v:
ruby 1.9.1p0 (2009-01-30 revision 21907) [i386-darwin9.6.0]
[ruby-core:23642]

Description

=begin
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?
=end

History

#1

Updated by matz (Yukihiro Matsumoto) over 10 years ago

=begin
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.

=end

#2

Updated by brianmario (Brian Lopez) over 10 years ago

=begin
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).
=end

#3

Updated by rogerdpack (Roger Pack) over 9 years ago

=begin
Can you extract a small reproducible script?
-r
=end

#4

Updated by mame (Yusuke Endoh) over 9 years ago

  • Status changed from Open to Feedback

=begin
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
=end

#5

Updated by brianmario (Brian Lopez) over 9 years ago

=begin
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)
=end

#6

Updated by naruse (Yui NARUSE) over 9 years ago

  • Status changed from Feedback to Open

=begin

=end

#7

Updated by jeremyevans0 (Jeremy Evans) about 2 months ago

  • Status changed from Open to Closed
  • Description updated (diff)

Also available in: Atom PDF