Why is JRuby read_nonblock blocking?
I'm trying to add an error log to a JRuby process that reads data from the stdout of one subprocess and writes that data to the stdin of another subprocess, while collecting some statistics on the data at the same time. Subprocesses are created using IO.popen4
.
To read the error streams, I cannot use blocking reads, because normally there is no exit on those streams. However, when I use read_nonblock
in these threads, I am still experiencing read locks in JRuby.
Why block calls read_nonblock
and how can I rewrite this code so that it never blocks and always displays any stderr that is called by the subprocess?
Below is a simplified version of the code in use that reproduces the problem. It blocks on jruby and doesn't render the expected result to ruby 1.9.3p194 (2012-04-20 revision 35410) [x86_64-darwin11.4.0]
.
if RUBY_PLATFORM != "java" && RUBY_VERSION =~ /^1\.9/
class IO
def self.popen4(*args, &block)
require "open4"
Open4::popen4(*args, &block)
end
end
end
IO.popen4('echo', 'hi') do |_, _, stdout1, stderr1|
IO.popen4('sh', '-c', 'cat 1>&2') do |_, stdin2, _, stderr2|
stdout1.each_line do |line|
stdin2 << line
(IO.select([stderr1, stderr2], [], [], 0.1) or [[]]).first.each do |stream|
begin
# in jruby 1.6.8 (ruby-1.9.2-p312) (2012-09-18 1772b40) (Java HotSpot(TM) Client VM 1.6.0_37) [darwin-i386-java], read_nonblock blocks
# idem in jruby 1.7.2 (1.9.3p327) 2013-01-04 302c706 on Java HotSpot(TM) Client VM 1.6.0_37-b06-434-11M3909 [darwin-i386]
puts stream.read_nonblock(1000)
rescue Exception => e
puts e.message
end
end
end
end
end
I know it is locked in read_nonblock due to the stack trace when pressing ctrl + \:
"main" prio=5 tid=0000000003110800 nid=0xb0201000 runnable [00000000b01ff000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.FileDispatcher.read0(Native Method)
at sun.nio.ch.FileDispatcher.read(FileDispatcher.java:26)
at sun.nio.ch.IOUtil.readIntoNativeBuffer(IOUtil.java:198)
at sun.nio.ch.IOUtil.read(IOUtil.java:171)
at sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:144)
- locked <0000000006158308> (a java.lang.Object)
at org.jruby.util.io.ChannelStream.refillBuffer(ChannelStream.java:196)
at org.jruby.util.io.ChannelStream.bufferedRead(ChannelStream.java:926)
at org.jruby.util.io.ChannelStream.bufferedRead(ChannelStream.java:888)
at org.jruby.util.io.ChannelStream.fread(ChannelStream.java:1288)
- locked <000000000615a8f8> (a org.jruby.util.io.ChannelStream)
at org.jruby.util.io.ChannelStream.readnonblock(ChannelStream.java:1314)
- locked <000000000615a8f8> (a org.jruby.util.io.ChannelStream)
at org.jruby.RubyIO.getPartial(RubyIO.java:2762)
at org.jruby.RubyIO.read_nonblock(RubyIO.java:2697)
at org.jruby.RubyIO$INVOKER$i$0$1$read_nonblock.call(RubyIO$INVOKER$i$0$1$read_nonblock.gen)
at org.jruby.internal.runtime.methods.JavaMethod$JavaMethodN.call(JavaMethod.java:646)
at org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:204)
at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:168)
at read_nonblock_test.chained_2_rescue_1$RUBY$SYNTHETIC__file__(read_nonblock_test.rb:19)
at read_nonblock_test.block_3$RUBY$__file__(read_nonblock_test.rb:16)
at read_nonblock_test$block_3$RUBY$__file__.call(read_nonblock_test$block_3$RUBY$__file__)
at org.jruby.runtime.CompiledBlock19.yield(CompiledBlock19.java:139)
at org.jruby.runtime.Block.yield(Block.java:130)
...
source to share
So, this is a pretty offensive solution, but this is what worked for me. Since select always returns "yes" and non-blocking just doesn't work, I don't see any other choice:
require 'timeout'
begin
while true
line = nil
Timeout::timeout(1) { line=io.gets }
if line.nil?
break
else
puts "line: #{line}"
end
end
rescue Timeout::Error
end
-Robin
source to share
(in fact, this is not an answer, rather a continuation of the problem)
Mine never blocks (1.6.8) but always returns EAGAIN. I have not yet found a way to detect-data-but-not-block with a pipe in jruby:
jruby-1.6.8 :001 > io=IO.popen('sh -c "sleep 10"') ; select([io],nil,nil,0)
=> [[#<IO:0x6e72d873>], [], []]
jruby-1.6.8 :003 > sleep 10 ; begin ; io.read_nonblock(1) ; rescue Exception => e ; puts "nothing: #{e.class.name}" ; puts "#{io.eof?}" ; end
nothing: Errno::EAGAIN
true
=> nil
jruby-1.6.8 :001 > io=IO.popen('sh -c "sleep 10"') ; select([io],nil,nil,0)
=> [[#<IO:0x6e72d873>], [], []]
jruby-1.6.8 :006 > require 'fcntl'; io=IO.popen('sh -c "sleep 10"') ; puts "f: #{io.fcntl(Fcntl::F_GETFL)}" ; io.fcntl(Fcntl::F_SETFL, Fcntl::O_NONBLOCK) ; puts "f: #{io.fcntl(Fcntl::F_GETFL)}" ; puts "e: #{io.gets}"
f: 0
f: 0
e:
=> nil
jruby-1.6.8 :007 > io=IO.popen('sh -c "echo foo ; sleep 10"') ; select([io],nil,nil,0) ; begin ; io.read_nonblock(1) ; rescue Exception => e ; puts "nothing: #{e.class.name}" ; puts "#{io.eof?}" ; end
nothing: Errno::EAGAIN
false
=> nil
Not that read_nonblock returns EAGAIN when data is present! And at EOF! 0.o
-Robin
source to share