New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

use of jruby causes “Errno::EBADF: Bad file descriptor” error #5249

Open
voyager131 opened this Issue Jul 13, 2018 · 19 comments

Comments

Projects
None yet
3 participants
@voyager131

voyager131 commented Jul 13, 2018

This is posted to StackOverflow as well.

I've got a little executable we'll call "decode" (written in C) that takes a block of data on stdin (an image file), converts it, and spits it back to stdout. So from the linux command line the following command works just fine:

cat image_file.format1 | ./irb/decode > image_file.format2

I'm trying to wrap this binary in some ruby code and eliminate the need for the use of regular file IO using Open3.popen3. Here's the relevant section of Ruby code:

.
.
.
Open3.popen3("decode") do |stdin, stdout, stderr, wait_thr|
  stdin.write(f)
  stdin.close_write
  @image_data = stdout.read
  @status_message = stderr.read
  exit_status = wait_thr.value
end
.
.
.

Variable f contains the block of data to convert. I was writing it to file and then calling decode on the written file. When trying to run the the above code from irb using jruby, one gets the following error traceback (slightly sanitized):

Traceback (most recent call last):
   16: from org/jruby/RubyKernel.java:1180:in `catch'
   15: from org/jruby/RubyKernel.java:1418:in `loop'
   14: from org/jruby/RubyKernel.java:1037:in `eval'
   13: from t:5:in `<eval>'
   12: from /home/user/dev/kf_decoder/lib/kf_decoder/kob.rb:46:in `process'
   11: from org/jruby/RubyKernel.java:311:in `open'
   10: from org/jruby/RubyIO.java:1179:in `open'
    9: from /home/user/dev/kf_decoder/lib/kf_decoder/kob.rb:63:in `block in process'
    8: from org/jruby/ext/stringio/StringIO.java:423:in `each_byte'
    7: from /home/user/dev/kf_decoder/lib/kf_decoder/kob.rb:87:in `block in process'
    6: from /home/user/dev/kf_decoder/lib/kf_decoder/kob.rb:205:in `decodeTiff'
    5: from /home/user/dev/kf_decoder/lib/kf_decoder/tiff.rb:123:in `initialize'
    4: from /home/user/.rbenv/versions/jruby-9.2.0.0/lib/ruby/stdlib/open3.rb:102:in `popen3'
    3: from /home/user/.rbenv/versions/jruby-9.2.0.0/lib/ruby/stdlib/open3.rb:206:in `popen_run'
    2: from org/jruby/RubyKernel.java:1642:in `spawn'
    1: from org/jruby/RubyProcess.java:1570:in `spawn'
Errno::EBADF (Bad file descriptor - irb/decode

The funny thing is that the exact same code works fine unchanged in irb if I'm using the system ruby interpreter, or rubinius (both of which I have installed and can switch between using rbenv).

Can anyone tell me what gives? I'm runing ubuntu linux 18.04 LTS, and jruby 9.2.0.0 (2.5.0). Jruby is the platform of choice because of speed and other considerations, so I need to get this working.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jul 13, 2018

Member

EBADF would generally mean that one of the IO streams to the subprocess have been shut down, perhaps prematurely.

Can you put together a small git repo that we can clone and run to see the problem locally?

Member

headius commented Jul 13, 2018

EBADF would generally mean that one of the IO streams to the subprocess have been shut down, perhaps prematurely.

Can you put together a small git repo that we can clone and run to see the problem locally?

@headius headius added this to the JRuby 9.2.1.0 milestone Jul 13, 2018

@voyager131

This comment has been minimized.

Show comment
Hide comment
@voyager131

voyager131 Jul 13, 2018

Alright. I'll work on trying to put together a bit of code that reproduces the error. Might take me into next week. I didn't post until I'd pretty much exhausted google and cross tested every other alternative. Stay tuned.

voyager131 commented Jul 13, 2018

Alright. I'll work on trying to put together a bit of code that reproduces the error. Might take me into next week. I didn't post until I'd pretty much exhausted google and cross tested every other alternative. Stay tuned.

@voyager131

This comment has been minimized.

Show comment
Hide comment
@voyager131

voyager131 Jul 13, 2018

OK, so it didn't take too long to cook up a demo. Here's a file-set on Github that should allow you to reproduce the problem.

run the .rb file in jruby and you should get the following error:

user@host:~/tmp/jruby-bug$ ruby bugdemo.rb
Errno::ENOENT: No such file or directory - decode
spawn at org/jruby/RubyProcess.java:1570
spawn at org/jruby/RubyKernel.java:1642
popen_run at /home/user/.rbenv/versions/jruby-9.2.0.0/lib/ruby/stdlib/open3.rb:206
popen3 at /home/user/.rbenv/versions/jruby-9.2.0.0/lib/ruby/stdlib/open3.rb:102
<main> at bugdemo.rb:12

As I said before, the code runs fine with system ruby and rubinius (no error). With either of those, you'll get a tiff file you can open with any image viewer program. Thanks for the help in figuring this out.

voyager131 commented Jul 13, 2018

OK, so it didn't take too long to cook up a demo. Here's a file-set on Github that should allow you to reproduce the problem.

run the .rb file in jruby and you should get the following error:

user@host:~/tmp/jruby-bug$ ruby bugdemo.rb
Errno::ENOENT: No such file or directory - decode
spawn at org/jruby/RubyProcess.java:1570
spawn at org/jruby/RubyKernel.java:1642
popen_run at /home/user/.rbenv/versions/jruby-9.2.0.0/lib/ruby/stdlib/open3.rb:206
popen3 at /home/user/.rbenv/versions/jruby-9.2.0.0/lib/ruby/stdlib/open3.rb:102
<main> at bugdemo.rb:12

As I said before, the code runs fine with system ruby and rubinius (no error). With either of those, you'll get a tiff file you can open with any image viewer program. Thanks for the help in figuring this out.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jul 13, 2018

Member

I think there's a bug in the demo script you provided; it can't find the decode executable. I changed it from Open3.popen3("decode") to Open3.popen3("./decode") and the ENOENT went away.

Unfortunately, I also did not get EBADF:

vagrant@ubuntu-xenial:~/jruby-bug-5249$ jruby bugdemo.rb 
Conversion complete. 

With my change, does the script give you an EBADF, or do we need to keep looking for a reproduction?

Member

headius commented Jul 13, 2018

I think there's a bug in the demo script you provided; it can't find the decode executable. I changed it from Open3.popen3("decode") to Open3.popen3("./decode") and the ENOENT went away.

Unfortunately, I also did not get EBADF:

vagrant@ubuntu-xenial:~/jruby-bug-5249$ jruby bugdemo.rb 
Conversion complete. 

With my change, does the script give you an EBADF, or do we need to keep looking for a reproduction?

@voyager131

This comment has been minimized.

Show comment
Hide comment
@voyager131

voyager131 Jul 15, 2018

I've updated my script with your change, inserting a "./" in front of decode. I get the same error.

user@host:~/tmp/jruby-bug$ ruby bugdemo.rb 
Errno::EBADF: Bad file descriptor - ./decode
      spawn at org/jruby/RubyProcess.java:1570
      spawn at org/jruby/RubyKernel.java:1642
  popen_run at /home/user/.rbenv/versions/jruby-9.2.0.0/lib/ruby/stdlib/open3.rb:206
     popen3 at /home/user/.rbenv/versions/jruby-9.2.0.0/lib/ruby/stdlib/open3.rb:102
     <main> at bugdemo.rb:12

Here's a file listing in case there's something wrong there (I can't see what)

user@host:~/tmp/jruby-bug$ ll
total 56
-rw-rw-r-- 1 user user   877 Jul 15 07:35 bugdemo.rb
-rwxrwxr-x 1 user user 27792 Jul 13 11:36 decode*
-rw-rw-r-- 1 user user    17 Jul 13 11:51 README.md
-rw-r--r-- 1 user user 20141 Jul 13 11:22 test.kob

And for good measure I've run the executable manually as follows:

user@host:~/tmp/jruby-bug$ cat test.kob | ./decode > test.tiff
user@host:~/tmp/jruby-bug$ ls
bugdemo.rb  decode  README.md  test.kob  test.tiff
user@host:~/tmp/jruby-bug$ 

It produced the expected tiff file without issue. Switching over to system ruby with rbenv global system and running the script again produces the following result:

user@host:~/tmp/jruby-bug$ ruby bugdemo.rb
Conversion complete. 
user@host:~/tmp/jruby-bug$ 

Ditto for rbx (rubinius) which I also have installed. Clearly, there's something wrong with my installation of jruby.

PS. I've updated the GIT repo with the minor tweak to bugdemo.rb.

voyager131 commented Jul 15, 2018

I've updated my script with your change, inserting a "./" in front of decode. I get the same error.

user@host:~/tmp/jruby-bug$ ruby bugdemo.rb 
Errno::EBADF: Bad file descriptor - ./decode
      spawn at org/jruby/RubyProcess.java:1570
      spawn at org/jruby/RubyKernel.java:1642
  popen_run at /home/user/.rbenv/versions/jruby-9.2.0.0/lib/ruby/stdlib/open3.rb:206
     popen3 at /home/user/.rbenv/versions/jruby-9.2.0.0/lib/ruby/stdlib/open3.rb:102
     <main> at bugdemo.rb:12

Here's a file listing in case there's something wrong there (I can't see what)

user@host:~/tmp/jruby-bug$ ll
total 56
-rw-rw-r-- 1 user user   877 Jul 15 07:35 bugdemo.rb
-rwxrwxr-x 1 user user 27792 Jul 13 11:36 decode*
-rw-rw-r-- 1 user user    17 Jul 13 11:51 README.md
-rw-r--r-- 1 user user 20141 Jul 13 11:22 test.kob

And for good measure I've run the executable manually as follows:

user@host:~/tmp/jruby-bug$ cat test.kob | ./decode > test.tiff
user@host:~/tmp/jruby-bug$ ls
bugdemo.rb  decode  README.md  test.kob  test.tiff
user@host:~/tmp/jruby-bug$ 

It produced the expected tiff file without issue. Switching over to system ruby with rbenv global system and running the script again produces the following result:

user@host:~/tmp/jruby-bug$ ruby bugdemo.rb
Conversion complete. 
user@host:~/tmp/jruby-bug$ 

Ditto for rbx (rubinius) which I also have installed. Clearly, there's something wrong with my installation of jruby.

PS. I've updated the GIT repo with the minor tweak to bugdemo.rb.

@voyager131

This comment has been minimized.

Show comment
Hide comment
@voyager131

voyager131 Jul 16, 2018

I found this explanation from a post of yours quite some time ago. I don't know if it is relevant or not.

In JRuby, because we don't normally have access to the "real" file
descriptor for any IO channel, all our logic for fileno is basically
fake. We keep an artificial list of numbers that map to IO channels
and use that as our file descriptor table. In this case, you're
pulling in a real file descriptor from the system, which does not
exist in our table, so we raise an error.

In order for us to support arbitrary descriptors in our IO we'd
probably need an implementation of IO that used all low-level C APIs
rather than Java IO APIs. There's currently no (public) way to get
from a file descriptor to an IO channel in Java APIs.

So I'll divert this issue by asking: what does this get you that our
built-in tempfile support does not? We do not use MRI's tempfile.rb;
we've implemented our own on top of Java's tempfile support that
performs quite a bit better. Perhaps there's a missing feature we can
add.

My point in using pipes is to improve performance over std disk-based file I/O. The code I've abstracted for the demo is part of a larger system that performs repeated conversions, hundreds of thousands of them in fact, and needs to do so as quickly as possible. That's why the code that actually does the converting is written in C and compiled. That's just step 1 though as I need to get the data to convert to the binary, and the converted data back from it, as quickly and as efficiently as possible.

The earlier version of the code that used temporary files worked, but it also occasionally would throw an "Errno::EBADF: Bad file descriptor" error. I'm using multiple threads in a worker pool (Celluloid) to fire off as many of these conversions at once as the system can handle. It smelled to me in the temp-file version that I was running into a resource problem, but given that std file I/O is not as efficient as pipes theoretically, I moved to that. But I'm not even getting off first base with the new pipe-based code.

If there's a better way to do what I need to do in jRuby, I'm open.

voyager131 commented Jul 16, 2018

I found this explanation from a post of yours quite some time ago. I don't know if it is relevant or not.

In JRuby, because we don't normally have access to the "real" file
descriptor for any IO channel, all our logic for fileno is basically
fake. We keep an artificial list of numbers that map to IO channels
and use that as our file descriptor table. In this case, you're
pulling in a real file descriptor from the system, which does not
exist in our table, so we raise an error.

In order for us to support arbitrary descriptors in our IO we'd
probably need an implementation of IO that used all low-level C APIs
rather than Java IO APIs. There's currently no (public) way to get
from a file descriptor to an IO channel in Java APIs.

So I'll divert this issue by asking: what does this get you that our
built-in tempfile support does not? We do not use MRI's tempfile.rb;
we've implemented our own on top of Java's tempfile support that
performs quite a bit better. Perhaps there's a missing feature we can
add.

My point in using pipes is to improve performance over std disk-based file I/O. The code I've abstracted for the demo is part of a larger system that performs repeated conversions, hundreds of thousands of them in fact, and needs to do so as quickly as possible. That's why the code that actually does the converting is written in C and compiled. That's just step 1 though as I need to get the data to convert to the binary, and the converted data back from it, as quickly and as efficiently as possible.

The earlier version of the code that used temporary files worked, but it also occasionally would throw an "Errno::EBADF: Bad file descriptor" error. I'm using multiple threads in a worker pool (Celluloid) to fire off as many of these conversions at once as the system can handle. It smelled to me in the temp-file version that I was running into a resource problem, but given that std file I/O is not as efficient as pipes theoretically, I moved to that. But I'm not even getting off first base with the new pipe-based code.

If there's a better way to do what I need to do in jRuby, I'm open.

@voyager131

This comment has been minimized.

Show comment
Hide comment
@voyager131

voyager131 Jul 18, 2018

Just tried the bug demo code with jruby 9.2.1... no joy.

voyager131 commented Jul 18, 2018

Just tried the bug demo code with jruby 9.2.1... no joy.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jul 19, 2018

Member

I am traveling but will try to look at this again soon. I suspect it is a difference in how we do IO or handle errors on Linux versus MacOS (I'm testing on MacOS).

@enebo Can you reproduce this?

Member

headius commented Jul 19, 2018

I am traveling but will try to look at this again soon. I suspect it is a difference in how we do IO or handle errors on Linux versus MacOS (I'm testing on MacOS).

@enebo Can you reproduce this?

@voyager131

This comment has been minimized.

Show comment
Hide comment
@voyager131

voyager131 Jul 19, 2018

voyager131 commented Jul 19, 2018

@enebo

This comment has been minimized.

Show comment
Hide comment
@enebo

enebo Jul 19, 2018

Member

@voyager131 @headius ok something fascinating here...If I run it using Java 8 it runs quickly. If I run with Java 9 or Java 10 it just sits there. Here is a dump:

2018-07-19 16:42:02
Full thread dump Java HotSpot(TM) 64-Bit Server VM (10.0.1+10 mixed mode):

Threads class SMR info:
_java_thread_list=0x00007f13006c9160, length=13, elements={
0x00007f1300011000, 0x00007f13001df800, 0x00007f13001e1800, 0x00007f13001ea800,
0x00007f13001f5000, 0x00007f13001f7000, 0x00007f13001f9000, 0x00007f13001fb000,
0x00007f13001fd000, 0x00007f13002c9800, 0x00007f13002d4000, 0x00007f130097a800,
0x00007f1300988800
}

"main" #1 prio=5 os_prio=0 tid=0x00007f1300011000 nid=0x143e runnable  [0x00007f1305b5c000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.EPollArrayWrapper.epollWait(java.base@10.0.1/Native Method)
	at sun.nio.ch.EPollArrayWrapper.poll(java.base@10.0.1/EPollArrayWrapper.java:265)
	at sun.nio.ch.EPollSelectorImpl.doSelect(java.base@10.0.1/EPollSelectorImpl.java:92)
	at sun.nio.ch.SelectorImpl.lockAndDoSelect(java.base@10.0.1/SelectorImpl.java:89)
	- locked <0x00000006dd5211c0> (a sun.nio.ch.Util$2)
	- locked <0x00000006dd521130> (a java.util.Collections$UnmodifiableSet)
	- locked <0x00000006dd521018> (a sun.nio.ch.EPollSelectorImpl)
	at sun.nio.ch.SelectorImpl.select(java.base@10.0.1/SelectorImpl.java:100)
	at sun.nio.ch.SelectorImpl.select(java.base@10.0.1/SelectorImpl.java:104)
	at org.jruby.RubyThread.select(RubyThread.java:1906)
	- locked <0x00000006dab567d8> (a java.lang.Object)
	at org.jruby.RubyThread.select(RubyThread.java:1827)
	at org.jruby.util.io.OpenFile.readInternal(OpenFile.java:1383)
	at org.jruby.util.io.OpenFile.ioBufread(OpenFile.java:1735)
	at org.jruby.util.io.OpenFile.bufreadCall(OpenFile.java:1775)
	at org.jruby.util.io.OpenFile.fread(OpenFile.java:1792)
	at org.jruby.util.io.OpenFile.readAll(OpenFile.java:1696)
	at org.jruby.RubyIO.read(RubyIO.java:3055)
	at org.jruby.RubyIO.read(RubyIO.java:3037)
	at org.jruby.RubyIO$INVOKER$i$read.call(RubyIO$INVOKER$i$read.gen)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:323)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:139)
	at bugdemo.invokeOther2:read(bugdemo.rb:15)
	at bugdemo.RUBY$block$\=bugdemo\,rb$0(bugdemo.rb:15)
	at java.lang.invoke.DirectMethodHandle$Holder.invokeStatic(java.base@10.0.1/DirectMethodHandle$Holder)
	at java.lang.invoke.LambdaForm$MH/1657842786.invoke(java.base@10.0.1/LambdaForm$MH)
	at java.lang.invoke.Invokers$Holder.invokeExact_MT(java.base@10.0.1/Invokers$Holder)
	at org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:134)
	at org.jruby.runtime.BlockBody.yield(BlockBody.java:122)
	at org.jruby.runtime.Block.yieldArray(Block.java:177)
	at org.jruby.ir.runtime.IRRuntimeHelpers.yield(IRRuntimeHelpers.java:460)
	at org.jruby.ir.instructions.YieldInstr.interpret(YieldInstr.java:83)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:178)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:104)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:103)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:90)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:301)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:82)
	at org.jruby.ir.instructions.CallBase.interpret(CallBase.java:522)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:360)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
	at org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:84)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:169)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:156)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:355)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:180)
	at org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:187)
	at bugdemo.invokeOther15:popen3(bugdemo.rb:12)
	at bugdemo.RUBY$script(bugdemo.rb:12)
	at java.lang.invoke.DirectMethodHandle$Holder.invokeStatic(java.base@10.0.1/DirectMethodHandle$Holder)
	at java.lang.invoke.LambdaForm$MH/800497654.invoke(java.base@10.0.1/LambdaForm$MH)
	at java.lang.invoke.LambdaForm$MH/530410619.invoke(java.base@10.0.1/LambdaForm$MH)
	at java.lang.invoke.LambdaForm$MH/756080817.invokeExact_MT(java.base@10.0.1/LambdaForm$MH)
	at java.lang.invoke.MethodHandle.invokeWithArguments(java.base@10.0.1/MethodHandle.java:707)
	at org.jruby.ir.Compiler$1.load(Compiler.java:94)
	at org.jruby.Ruby.runScript(Ruby.java:852)
	at org.jruby.Ruby.runNormally(Ruby.java:771)
	at org.jruby.Ruby.runNormally(Ruby.java:789)
	at org.jruby.Ruby.runFromMain(Ruby.java:601)
	at org.jruby.Main.doRunFromMain(Main.java:415)
	at org.jruby.Main.internalRun(Main.java:307)
	at org.jruby.Main.run(Main.java:234)
	at org.jruby.Main.main(Main.java:206)

"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f13001df800 nid=0x1454 waiting on condition  [0x00007f12b871e000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.ref.Reference.waitForReferencePendingList(java.base@10.0.1/Native Method)
	at java.lang.ref.Reference.processPendingReferences(java.base@10.0.1/Reference.java:174)
	at java.lang.ref.Reference.access$000(java.base@10.0.1/Reference.java:44)
	at java.lang.ref.Reference$ReferenceHandler.run(java.base@10.0.1/Reference.java:138)

"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f13001e1800 nid=0x1455 in Object.wait()  [0x00007f12b851d000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@10.0.1/Native Method)
	- waiting on <0x00000006dafbf188> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@10.0.1/ReferenceQueue.java:151)
	- waiting to re-lock in wait() <0x00000006dafbf188> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@10.0.1/ReferenceQueue.java:172)
	at java.lang.ref.Finalizer$FinalizerThread.run(java.base@10.0.1/Finalizer.java:216)

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f13001ea800 nid=0x1456 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f13001f5000 nid=0x1457 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f13001f7000 nid=0x1458 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"C2 CompilerThread2" #7 daemon prio=9 os_prio=0 tid=0x00007f13001f9000 nid=0x1459 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"C1 CompilerThread3" #8 daemon prio=9 os_prio=0 tid=0x00007f13001fb000 nid=0x145a waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"Sweeper thread" #9 daemon prio=9 os_prio=0 tid=0x00007f13001fd000 nid=0x145b runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Service Thread" #10 daemon prio=9 os_prio=0 tid=0x00007f13002c9800 nid=0x145c runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Common-Cleaner" #11 daemon prio=8 os_prio=0 tid=0x00007f13002d4000 nid=0x145d in Object.wait()  [0x00007f126f229000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(java.base@10.0.1/Native Method)
	- waiting on <0x00000006dafb0528> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@10.0.1/ReferenceQueue.java:151)
	- waiting to re-lock in wait() <0x00000006dafb0528> (a java.lang.ref.ReferenceQueue$Lock)
	at jdk.internal.ref.CleanerImpl.run(java.base@10.0.1/CleanerImpl.java:148)
	at java.lang.Thread.run(java.base@10.0.1/Thread.java:844)
	at jdk.internal.misc.InnocuousThread.run(java.base@10.0.1/InnocuousThread.java:134)

"jnr.ffi.util.ref.internal.Finalizer" #15 daemon prio=10 os_prio=0 tid=0x00007f130097a800 nid=0x145f in Object.wait()  [0x00007f126cfc0000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@10.0.1/Native Method)
	- waiting on <0x00000006dd519940> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@10.0.1/ReferenceQueue.java:151)
	- waiting to re-lock in wait() <0x00000006dd519940> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@10.0.1/ReferenceQueue.java:172)
	at jnr.ffi.util.ref.internal.Finalizer.run(Finalizer.java:180)
	at java.lang.Thread.run(java.base@10.0.1/Thread.java:844)

"Ruby-0-Thread-1: /home/enebo/work/jruby/lib/ruby/stdlib/open3.rb:207" #16 daemon prio=5 os_prio=0 tid=0x00007f1300988800 nid=0x1461 runnable  [0x00007f126cdbf000]
   java.lang.Thread.State: RUNNABLE
	at com.kenai.jffi.Foreign.invokeN3O1(Native Method)
	at com.kenai.jffi.Invoker.invokeN3(Invoker.java:1061)
	at jnr.posix.LinuxLibC$jnr$ffi$0.waitpid(Unknown Source)
	at jnr.posix.BaseNativePOSIX.waitpid(BaseNativePOSIX.java:490)
	at jnr.posix.CheckedPOSIX.waitpid(CheckedPOSIX.java:399)
	at jnr.posix.LazyPOSIX.waitpid(LazyPOSIX.java:394)
	at jnr.posix.LazyPOSIX.waitpid(LazyPOSIX.java:390)
	at org.jruby.RubyProcess$2.call(RubyProcess.java:1370)
	at org.jruby.runtime.CallBlock.call(CallBlock.java:77)
	at org.jruby.runtime.Block.call(Block.java:124)
	at org.jruby.RubyProc.call(RubyProc.java:286)
	at org.jruby.RubyProc.call(RubyProc.java:270)
	at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:105)
	at java.lang.Thread.run(java.base@10.0.1/Thread.java:844)

"VM Thread" os_prio=0 tid=0x00007f13001d5800 nid=0x1453 runnable  

"GC Thread#0" os_prio=0 tid=0x00007f1300031000 nid=0x143f runnable  

"GC Thread#1" os_prio=0 tid=0x00007f1300032800 nid=0x1440 runnable  

"GC Thread#2" os_prio=0 tid=0x00007f1300034000 nid=0x1441 runnable  

"GC Thread#3" os_prio=0 tid=0x00007f1300035800 nid=0x1442 runnable  

"GC Thread#4" os_prio=0 tid=0x00007f1300037800 nid=0x1443 runnable  

"GC Thread#5" os_prio=0 tid=0x00007f1300039000 nid=0x1444 runnable  

"GC Thread#6" os_prio=0 tid=0x00007f130003b000 nid=0x1445 runnable  

"GC Thread#7" os_prio=0 tid=0x00007f130003c800 nid=0x1446 runnable  

"G1 Main Marker" os_prio=0 tid=0x00007f1300089000 nid=0x1447 runnable  

"G1 Conc#0" os_prio=0 tid=0x00007f130008b000 nid=0x1448 runnable  

"G1 Conc#1" os_prio=0 tid=0x00007f130008c800 nid=0x1449 runnable  

"G1 Refine#0" os_prio=0 tid=0x00007f1300164000 nid=0x144a runnable  

"G1 Refine#1" os_prio=0 tid=0x00007f1300165800 nid=0x144b runnable  

"G1 Refine#2" os_prio=0 tid=0x00007f1300167800 nid=0x144c runnable  

"G1 Refine#3" os_prio=0 tid=0x00007f1300169800 nid=0x144d runnable  

"G1 Refine#4" os_prio=0 tid=0x00007f130016b000 nid=0x144e runnable  

"G1 Refine#5" os_prio=0 tid=0x00007f130016d000 nid=0x144f runnable  

"G1 Refine#6" os_prio=0 tid=0x00007f130016e800 nid=0x1450 runnable  

"G1 Refine#7" os_prio=0 tid=0x00007f1300170800 nid=0x1451 runnable  

"G1 Young RemSet Sampling" os_prio=0 tid=0x00007f1300172000 nid=0x1452 runnable  
"VM Periodic Task Thread" os_prio=0 tid=0x00007f13002d7800 nid=0x145e waiting on condition  

JNI global references: 14

Heap
 garbage-first heap   total 247808K, used 12860K [0x00000006ce400000, 0x00000007c0000000)
  region size 1024K, 12 young (12288K), 10 survivors (10240K)
 Metaspace       used 35647K, capacity 36231K, committed 36560K, reserved 1081344K
  class space    used 5282K, capacity 5460K, committed 5584K, reserved 1048576K

I do not seem to get EBADF but it just doesn't work...

Member

enebo commented Jul 19, 2018

@voyager131 @headius ok something fascinating here...If I run it using Java 8 it runs quickly. If I run with Java 9 or Java 10 it just sits there. Here is a dump:

2018-07-19 16:42:02
Full thread dump Java HotSpot(TM) 64-Bit Server VM (10.0.1+10 mixed mode):

Threads class SMR info:
_java_thread_list=0x00007f13006c9160, length=13, elements={
0x00007f1300011000, 0x00007f13001df800, 0x00007f13001e1800, 0x00007f13001ea800,
0x00007f13001f5000, 0x00007f13001f7000, 0x00007f13001f9000, 0x00007f13001fb000,
0x00007f13001fd000, 0x00007f13002c9800, 0x00007f13002d4000, 0x00007f130097a800,
0x00007f1300988800
}

"main" #1 prio=5 os_prio=0 tid=0x00007f1300011000 nid=0x143e runnable  [0x00007f1305b5c000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.EPollArrayWrapper.epollWait(java.base@10.0.1/Native Method)
	at sun.nio.ch.EPollArrayWrapper.poll(java.base@10.0.1/EPollArrayWrapper.java:265)
	at sun.nio.ch.EPollSelectorImpl.doSelect(java.base@10.0.1/EPollSelectorImpl.java:92)
	at sun.nio.ch.SelectorImpl.lockAndDoSelect(java.base@10.0.1/SelectorImpl.java:89)
	- locked <0x00000006dd5211c0> (a sun.nio.ch.Util$2)
	- locked <0x00000006dd521130> (a java.util.Collections$UnmodifiableSet)
	- locked <0x00000006dd521018> (a sun.nio.ch.EPollSelectorImpl)
	at sun.nio.ch.SelectorImpl.select(java.base@10.0.1/SelectorImpl.java:100)
	at sun.nio.ch.SelectorImpl.select(java.base@10.0.1/SelectorImpl.java:104)
	at org.jruby.RubyThread.select(RubyThread.java:1906)
	- locked <0x00000006dab567d8> (a java.lang.Object)
	at org.jruby.RubyThread.select(RubyThread.java:1827)
	at org.jruby.util.io.OpenFile.readInternal(OpenFile.java:1383)
	at org.jruby.util.io.OpenFile.ioBufread(OpenFile.java:1735)
	at org.jruby.util.io.OpenFile.bufreadCall(OpenFile.java:1775)
	at org.jruby.util.io.OpenFile.fread(OpenFile.java:1792)
	at org.jruby.util.io.OpenFile.readAll(OpenFile.java:1696)
	at org.jruby.RubyIO.read(RubyIO.java:3055)
	at org.jruby.RubyIO.read(RubyIO.java:3037)
	at org.jruby.RubyIO$INVOKER$i$read.call(RubyIO$INVOKER$i$read.gen)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:323)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:139)
	at bugdemo.invokeOther2:read(bugdemo.rb:15)
	at bugdemo.RUBY$block$\=bugdemo\,rb$0(bugdemo.rb:15)
	at java.lang.invoke.DirectMethodHandle$Holder.invokeStatic(java.base@10.0.1/DirectMethodHandle$Holder)
	at java.lang.invoke.LambdaForm$MH/1657842786.invoke(java.base@10.0.1/LambdaForm$MH)
	at java.lang.invoke.Invokers$Holder.invokeExact_MT(java.base@10.0.1/Invokers$Holder)
	at org.jruby.runtime.CompiledIRBlockBody.yieldDirect(CompiledIRBlockBody.java:134)
	at org.jruby.runtime.BlockBody.yield(BlockBody.java:122)
	at org.jruby.runtime.Block.yieldArray(Block.java:177)
	at org.jruby.ir.runtime.IRRuntimeHelpers.yield(IRRuntimeHelpers.java:460)
	at org.jruby.ir.instructions.YieldInstr.interpret(YieldInstr.java:83)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.processOtherOp(StartupInterpreterEngine.java:178)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:104)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:103)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:90)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:301)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:82)
	at org.jruby.ir.instructions.CallBase.interpret(CallBase.java:522)
	at org.jruby.ir.interpreter.InterpreterEngine.processCall(InterpreterEngine.java:360)
	at org.jruby.ir.interpreter.StartupInterpreterEngine.interpret(StartupInterpreterEngine.java:72)
	at org.jruby.ir.interpreter.InterpreterEngine.interpret(InterpreterEngine.java:84)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.INTERPRET_METHOD(MixedModeIRMethod.java:169)
	at org.jruby.internal.runtime.methods.MixedModeIRMethod.call(MixedModeIRMethod.java:156)
	at org.jruby.runtime.callsite.CachingCallSite.cacheAndCall(CachingCallSite.java:355)
	at org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:180)
	at org.jruby.runtime.callsite.CachingCallSite.callIter(CachingCallSite.java:187)
	at bugdemo.invokeOther15:popen3(bugdemo.rb:12)
	at bugdemo.RUBY$script(bugdemo.rb:12)
	at java.lang.invoke.DirectMethodHandle$Holder.invokeStatic(java.base@10.0.1/DirectMethodHandle$Holder)
	at java.lang.invoke.LambdaForm$MH/800497654.invoke(java.base@10.0.1/LambdaForm$MH)
	at java.lang.invoke.LambdaForm$MH/530410619.invoke(java.base@10.0.1/LambdaForm$MH)
	at java.lang.invoke.LambdaForm$MH/756080817.invokeExact_MT(java.base@10.0.1/LambdaForm$MH)
	at java.lang.invoke.MethodHandle.invokeWithArguments(java.base@10.0.1/MethodHandle.java:707)
	at org.jruby.ir.Compiler$1.load(Compiler.java:94)
	at org.jruby.Ruby.runScript(Ruby.java:852)
	at org.jruby.Ruby.runNormally(Ruby.java:771)
	at org.jruby.Ruby.runNormally(Ruby.java:789)
	at org.jruby.Ruby.runFromMain(Ruby.java:601)
	at org.jruby.Main.doRunFromMain(Main.java:415)
	at org.jruby.Main.internalRun(Main.java:307)
	at org.jruby.Main.run(Main.java:234)
	at org.jruby.Main.main(Main.java:206)

"Reference Handler" #2 daemon prio=10 os_prio=0 tid=0x00007f13001df800 nid=0x1454 waiting on condition  [0x00007f12b871e000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.ref.Reference.waitForReferencePendingList(java.base@10.0.1/Native Method)
	at java.lang.ref.Reference.processPendingReferences(java.base@10.0.1/Reference.java:174)
	at java.lang.ref.Reference.access$000(java.base@10.0.1/Reference.java:44)
	at java.lang.ref.Reference$ReferenceHandler.run(java.base@10.0.1/Reference.java:138)

"Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007f13001e1800 nid=0x1455 in Object.wait()  [0x00007f12b851d000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@10.0.1/Native Method)
	- waiting on <0x00000006dafbf188> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@10.0.1/ReferenceQueue.java:151)
	- waiting to re-lock in wait() <0x00000006dafbf188> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@10.0.1/ReferenceQueue.java:172)
	at java.lang.ref.Finalizer$FinalizerThread.run(java.base@10.0.1/Finalizer.java:216)

"Signal Dispatcher" #4 daemon prio=9 os_prio=0 tid=0x00007f13001ea800 nid=0x1456 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007f13001f5000 nid=0x1457 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"C2 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007f13001f7000 nid=0x1458 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"C2 CompilerThread2" #7 daemon prio=9 os_prio=0 tid=0x00007f13001f9000 nid=0x1459 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"C1 CompilerThread3" #8 daemon prio=9 os_prio=0 tid=0x00007f13001fb000 nid=0x145a waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"Sweeper thread" #9 daemon prio=9 os_prio=0 tid=0x00007f13001fd000 nid=0x145b runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Service Thread" #10 daemon prio=9 os_prio=0 tid=0x00007f13002c9800 nid=0x145c runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Common-Cleaner" #11 daemon prio=8 os_prio=0 tid=0x00007f13002d4000 nid=0x145d in Object.wait()  [0x00007f126f229000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(java.base@10.0.1/Native Method)
	- waiting on <0x00000006dafb0528> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@10.0.1/ReferenceQueue.java:151)
	- waiting to re-lock in wait() <0x00000006dafb0528> (a java.lang.ref.ReferenceQueue$Lock)
	at jdk.internal.ref.CleanerImpl.run(java.base@10.0.1/CleanerImpl.java:148)
	at java.lang.Thread.run(java.base@10.0.1/Thread.java:844)
	at jdk.internal.misc.InnocuousThread.run(java.base@10.0.1/InnocuousThread.java:134)

"jnr.ffi.util.ref.internal.Finalizer" #15 daemon prio=10 os_prio=0 tid=0x00007f130097a800 nid=0x145f in Object.wait()  [0x00007f126cfc0000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@10.0.1/Native Method)
	- waiting on <0x00000006dd519940> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@10.0.1/ReferenceQueue.java:151)
	- waiting to re-lock in wait() <0x00000006dd519940> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@10.0.1/ReferenceQueue.java:172)
	at jnr.ffi.util.ref.internal.Finalizer.run(Finalizer.java:180)
	at java.lang.Thread.run(java.base@10.0.1/Thread.java:844)

"Ruby-0-Thread-1: /home/enebo/work/jruby/lib/ruby/stdlib/open3.rb:207" #16 daemon prio=5 os_prio=0 tid=0x00007f1300988800 nid=0x1461 runnable  [0x00007f126cdbf000]
   java.lang.Thread.State: RUNNABLE
	at com.kenai.jffi.Foreign.invokeN3O1(Native Method)
	at com.kenai.jffi.Invoker.invokeN3(Invoker.java:1061)
	at jnr.posix.LinuxLibC$jnr$ffi$0.waitpid(Unknown Source)
	at jnr.posix.BaseNativePOSIX.waitpid(BaseNativePOSIX.java:490)
	at jnr.posix.CheckedPOSIX.waitpid(CheckedPOSIX.java:399)
	at jnr.posix.LazyPOSIX.waitpid(LazyPOSIX.java:394)
	at jnr.posix.LazyPOSIX.waitpid(LazyPOSIX.java:390)
	at org.jruby.RubyProcess$2.call(RubyProcess.java:1370)
	at org.jruby.runtime.CallBlock.call(CallBlock.java:77)
	at org.jruby.runtime.Block.call(Block.java:124)
	at org.jruby.RubyProc.call(RubyProc.java:286)
	at org.jruby.RubyProc.call(RubyProc.java:270)
	at org.jruby.internal.runtime.RubyRunnable.run(RubyRunnable.java:105)
	at java.lang.Thread.run(java.base@10.0.1/Thread.java:844)

"VM Thread" os_prio=0 tid=0x00007f13001d5800 nid=0x1453 runnable  

"GC Thread#0" os_prio=0 tid=0x00007f1300031000 nid=0x143f runnable  

"GC Thread#1" os_prio=0 tid=0x00007f1300032800 nid=0x1440 runnable  

"GC Thread#2" os_prio=0 tid=0x00007f1300034000 nid=0x1441 runnable  

"GC Thread#3" os_prio=0 tid=0x00007f1300035800 nid=0x1442 runnable  

"GC Thread#4" os_prio=0 tid=0x00007f1300037800 nid=0x1443 runnable  

"GC Thread#5" os_prio=0 tid=0x00007f1300039000 nid=0x1444 runnable  

"GC Thread#6" os_prio=0 tid=0x00007f130003b000 nid=0x1445 runnable  

"GC Thread#7" os_prio=0 tid=0x00007f130003c800 nid=0x1446 runnable  

"G1 Main Marker" os_prio=0 tid=0x00007f1300089000 nid=0x1447 runnable  

"G1 Conc#0" os_prio=0 tid=0x00007f130008b000 nid=0x1448 runnable  

"G1 Conc#1" os_prio=0 tid=0x00007f130008c800 nid=0x1449 runnable  

"G1 Refine#0" os_prio=0 tid=0x00007f1300164000 nid=0x144a runnable  

"G1 Refine#1" os_prio=0 tid=0x00007f1300165800 nid=0x144b runnable  

"G1 Refine#2" os_prio=0 tid=0x00007f1300167800 nid=0x144c runnable  

"G1 Refine#3" os_prio=0 tid=0x00007f1300169800 nid=0x144d runnable  

"G1 Refine#4" os_prio=0 tid=0x00007f130016b000 nid=0x144e runnable  

"G1 Refine#5" os_prio=0 tid=0x00007f130016d000 nid=0x144f runnable  

"G1 Refine#6" os_prio=0 tid=0x00007f130016e800 nid=0x1450 runnable  

"G1 Refine#7" os_prio=0 tid=0x00007f1300170800 nid=0x1451 runnable  

"G1 Young RemSet Sampling" os_prio=0 tid=0x00007f1300172000 nid=0x1452 runnable  
"VM Periodic Task Thread" os_prio=0 tid=0x00007f13002d7800 nid=0x145e waiting on condition  

JNI global references: 14

Heap
 garbage-first heap   total 247808K, used 12860K [0x00000006ce400000, 0x00000007c0000000)
  region size 1024K, 12 young (12288K), 10 survivors (10240K)
 Metaspace       used 35647K, capacity 36231K, committed 36560K, reserved 1081344K
  class space    used 5282K, capacity 5460K, committed 5584K, reserved 1048576K

I do not seem to get EBADF but it just doesn't work...

@voyager131

This comment has been minimized.

Show comment
Hide comment
@voyager131

voyager131 Jul 19, 2018

That is indeed interesting. I am running java 10.

user@host:~/$ java --version
openjdk 10.0.1 2018-04-17
OpenJDK Runtime Environment (build 10.0.1+10-Ubuntu-3ubuntu1)
OpenJDK 64-Bit Server VM (build 10.0.1+10-Ubuntu-3ubuntu1, mixed mode)

You guys will have to be the judges though of what that might mean or how best to proceed with this new information. I know next to nothing about java, and only use it.

voyager131 commented Jul 19, 2018

That is indeed interesting. I am running java 10.

user@host:~/$ java --version
openjdk 10.0.1 2018-04-17
OpenJDK Runtime Environment (build 10.0.1+10-Ubuntu-3ubuntu1)
OpenJDK 64-Bit Server VM (build 10.0.1+10-Ubuntu-3ubuntu1, mixed mode)

You guys will have to be the judges though of what that might mean or how best to proceed with this new information. I know next to nothing about java, and only use it.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jul 21, 2018

Member

Ah-ha, Java 10...I think that's a detail I missed, but it could be important. Could you try downloading a Java 8 SDK and see if it works?

The problem on Java 9+ is that we need to conform to some new standards about reflectively digging around inside the JDK classes (something we call "cracking them open"). In the case of process IO, this may mean that we are unable to properly represent native IO because we have to use the JDK IO classes as-is.

I'm pulling 9 to my VM now over a slow connection and then I should be able to confirm this.

Member

headius commented Jul 21, 2018

Ah-ha, Java 10...I think that's a detail I missed, but it could be important. Could you try downloading a Java 8 SDK and see if it works?

The problem on Java 9+ is that we need to conform to some new standards about reflectively digging around inside the JDK classes (something we call "cracking them open"). In the case of process IO, this may mean that we are unable to properly represent native IO because we have to use the JDK IO classes as-is.

I'm pulling 9 to my VM now over a slow connection and then I should be able to confirm this.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jul 21, 2018

Member

Ok, I get a slightly different error than you do when I use Java 9, but it's failing:

vagrant@ubuntu-xenial:~/jruby-bug-5249$ jruby bugdemo.rb 
Errno::EPIPE: Broken pipe - No message available
                write at org/jruby/RubyIO.java:1480
                write at org/jruby/RubyIO.java:1451
  block in bugdemo.rb at bugdemo.rb:13
            popen_run at /home/vagrant/jruby/lib/ruby/stdlib/open3.rb:212
               popen3 at /home/vagrant/jruby/lib/ruby/stdlib/open3.rb:102
               <main> at bugdemo.rb:12
Member

headius commented Jul 21, 2018

Ok, I get a slightly different error than you do when I use Java 9, but it's failing:

vagrant@ubuntu-xenial:~/jruby-bug-5249$ jruby bugdemo.rb 
Errno::EPIPE: Broken pipe - No message available
                write at org/jruby/RubyIO.java:1480
                write at org/jruby/RubyIO.java:1451
  block in bugdemo.rb at bugdemo.rb:13
            popen_run at /home/vagrant/jruby/lib/ruby/stdlib/open3.rb:212
               popen3 at /home/vagrant/jruby/lib/ruby/stdlib/open3.rb:102
               <main> at bugdemo.rb:12
@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jul 21, 2018

Member

Interestingly, it sometimes succeeds for me.

Member

headius commented Jul 21, 2018

Interestingly, it sometimes succeeds for me.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jul 21, 2018

Member

Ok, some good news!

If I modify your script to just use IO.popen (which doesn't provide access to stderr) it appears to work every time.

stdin = IO.popen("./decode", 'r+');
tap do
  stdin.write(raw_data)
  stdin.close_write
  $image_data = stdin.read
  #$status_message = stderr.read
  #exit_status = wait_thr.value
end#

The problem you're seeing seems to stem from the implementation of popen3 and how we handle it.

Member

headius commented Jul 21, 2018

Ok, some good news!

If I modify your script to just use IO.popen (which doesn't provide access to stderr) it appears to work every time.

stdin = IO.popen("./decode", 'r+');
tap do
  stdin.write(raw_data)
  stdin.close_write
  $image_data = stdin.read
  #$status_message = stderr.read
  #exit_status = wait_thr.value
end#

The problem you're seeing seems to stem from the implementation of popen3 and how we handle it.

@headius

This comment has been minimized.

Show comment
Hide comment
@headius

headius Jul 21, 2018

Member

Ok more information...

It does appear that popen3 is getting a proper native PID for a directly-launched subprocess, rather than one faked through JDK classes. So my original theory about Java 9 interfering with the process launch seems to not be true.

However if I pause your script inside the popen3 block and check whether a thread has actually been started for wait_thr, I see only the main thread running. This may not be related to your issue, but it seems that Process.detach is having some kind of trouble.

Member

headius commented Jul 21, 2018

Ok more information...

It does appear that popen3 is getting a proper native PID for a directly-launched subprocess, rather than one faked through JDK classes. So my original theory about Java 9 interfering with the process launch seems to not be true.

However if I pause your script inside the popen3 block and check whether a thread has actually been started for wait_thr, I see only the main thread running. This may not be related to your issue, but it seems that Process.detach is having some kind of trouble.

@voyager131

This comment has been minimized.

Show comment
Hide comment
@voyager131

voyager131 Jul 22, 2018

So I have java 8 installed and working along side java 10. I can switch between them on the command line just fine using

sudo update-alternatives --config java
sudo update-alternatives --config javac

However this does not change the version of java jruby uses as jruby --version yields the same result (see above) regardless off the setting I choose for java using the above commands. Working on figuring out how to fix that. Since I use rbenv, it might be nice to have another version of jruby linked to a different java or something.

voyager131 commented Jul 22, 2018

So I have java 8 installed and working along side java 10. I can switch between them on the command line just fine using

sudo update-alternatives --config java
sudo update-alternatives --config javac

However this does not change the version of java jruby uses as jruby --version yields the same result (see above) regardless off the setting I choose for java using the above commands. Working on figuring out how to fix that. Since I use rbenv, it might be nice to have another version of jruby linked to a different java or something.

@voyager131

This comment has been minimized.

Show comment
Hide comment
@voyager131

voyager131 Jul 22, 2018

Good news!

user@host:~/tmp/jruby-bug$ jruby ./bugdemo.rb 
Conversion complete. 
user@host:~/tmp/jruby-bug$ jruby --version
jruby 9.2.0.0 (2.5.0) 2018-05-24 81156a8 Java HotSpot(TM) 64-Bit Server VM 25.181-b13 on 1.8.0_181-b13 +jit [linux-x86_64]

For those (like me) who aren't as familiar with switching out the version of java used by jruby, that is done using the JAVA_HOME, environment variable. To use jruby with java 10, $JAVA_HOME is set (on my system) to:

user@host:~$ echo $JAVA_HOME
/opt/java-jdk/jdk-10.0.1/

To use it with java 8, it must be set as follows:

user@host:~/tmp/jruby-bug$ echo $JAVA_HOME
/usr/lib/jvm/java-8-oracle/

The correct paths will likely vary based on your specific installation. In addition JAVA_OPTS must contain options compatible with the version of java set by JAVA_HOME (I had a problem with that, as java 10 requires some options in my case that java 8 doesn't support).

Thanks to @headius and @enebo, I think it is known what the basic issue is with jruby and java10 using popen3 specifically. I'm not sure it matters to me which java version I use as long as I can get the performance I'm after, and I do need popen3 as stderr is vital to what I'm doing. I'll do a bit more work with java8 and post some additional feedback in a day or so.

voyager131 commented Jul 22, 2018

Good news!

user@host:~/tmp/jruby-bug$ jruby ./bugdemo.rb 
Conversion complete. 
user@host:~/tmp/jruby-bug$ jruby --version
jruby 9.2.0.0 (2.5.0) 2018-05-24 81156a8 Java HotSpot(TM) 64-Bit Server VM 25.181-b13 on 1.8.0_181-b13 +jit [linux-x86_64]

For those (like me) who aren't as familiar with switching out the version of java used by jruby, that is done using the JAVA_HOME, environment variable. To use jruby with java 10, $JAVA_HOME is set (on my system) to:

user@host:~$ echo $JAVA_HOME
/opt/java-jdk/jdk-10.0.1/

To use it with java 8, it must be set as follows:

user@host:~/tmp/jruby-bug$ echo $JAVA_HOME
/usr/lib/jvm/java-8-oracle/

The correct paths will likely vary based on your specific installation. In addition JAVA_OPTS must contain options compatible with the version of java set by JAVA_HOME (I had a problem with that, as java 10 requires some options in my case that java 8 doesn't support).

Thanks to @headius and @enebo, I think it is known what the basic issue is with jruby and java10 using popen3 specifically. I'm not sure it matters to me which java version I use as long as I can get the performance I'm after, and I do need popen3 as stderr is vital to what I'm doing. I'll do a bit more work with java8 and post some additional feedback in a day or so.

@voyager131

This comment has been minimized.

Show comment
Hide comment
@voyager131

voyager131 Jul 23, 2018

So my code appears to work quite well under jruby/java8. So problem solved as far as my immediate need is concerned. This leaves things unresolved for users of java 10 (9?) however. I'll leave it to you guys to sort that out. Some final comments by one or both of you are probably appropriate prior to closing the thread, so I'll leave it to one of you to do that. I also don't know if this conversation results in some to-do on the jruby development side. Another reason I'll let one of you close this. Thanks again for the help. It is much appreciated.

voyager131 commented Jul 23, 2018

So my code appears to work quite well under jruby/java8. So problem solved as far as my immediate need is concerned. This leaves things unresolved for users of java 10 (9?) however. I'll leave it to you guys to sort that out. Some final comments by one or both of you are probably appropriate prior to closing the thread, so I'll leave it to one of you to do that. I also don't know if this conversation results in some to-do on the jruby development side. Another reason I'll let one of you close this. Thanks again for the help. It is much appreciated.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment