Skip to content
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

Open3::capture2 and friends hang on stdin_data on Java GTE 9 #5642

Closed
yaauie opened this Issue Mar 4, 2019 · 16 comments

Comments

Projects
None yet
5 participants
@yaauie
Copy link

yaauie commented Mar 4, 2019

Environment

Provide at least:

  • JRuby version (jruby -v) and command line (flags, JRUBY_OPTS, etc):
    jruby 9.2.5.0 (2.5.0) 2018-12-06 6d5a228 Java HotSpot(TM) 64-Bit Server VM 9.0.4+11 on 9.0.4+11 +jit [darwin-x86_64]
    
    and
    jruby 9.2.5.0 (2.5.0) 2018-12-06 6d5a228 Java HotSpot(TM) 64-Bit Server VM 11.0.1+13-LTS on 11.0.1+13-LTS +jit [darwin-x86_64]
    
  • Operating system and platform (e.g. uname -a):
    Darwin castrovel.local 16.7.0 Darwin Kernel Version 16.7.0: Sun Oct 28 22:30:19 PDT 2018; root:xnu-3789.73.27~1/RELEASE_X86_64 x86_64
    

Other relevant info you may wish to add:

  • Installed or activated gems: N/A
  • Application/framework version (e.g. Rails, Sinatra): N/A
  • Environment variables: N/A

Expected Behavior

  • When Open::capture2() (and friends) is given stdin_data: 'hello, world', the supplied string should be provided as stdin to the shelled out command
#!/usr/bin/env ruby
require 'open3'
$stderr.puts(RUBY_DESCRIPTION)
capture, status = Open3.capture2('cat', stdin_data: 'hello, world')
$stdout.puts(capture: capture, status: status)

-- cat.rb

With Java 8:

╭─{ yaauie@castrovel:~/src/yaauie/jruby-vs-java-11 }
╰─○ JAVA_HOME="$(/usr/libexec/java_home -v 1.8)" ruby cat.rb
jruby 9.2.5.0 (2.5.0) 2018-12-06 6d5a228 Java HotSpot(TM) 64-Bit Server VM 25.152-b16 on 1.8.0_152-b16 +jit [darwin-x86_64]
{:capture=>"hello, world", :status=>#<Process::Status: pid 18214 exit 0>}
[success]

Actual Behavior

With Java 9+

╭─{ yaauie@castrovel:~/src/yaauie/jruby-vs-java-11 }
╰─○ JAVA_HOME="$(/usr/libexec/java_home -v 9)" ruby cat.rb
jruby 9.2.5.0 (2.5.0) 2018-12-06 6d5a228 Java HotSpot(TM) 64-Bit Server VM 9.0.4+11 on 9.0.4+11 +jit [darwin-x86_64]

The command hangs at this point; when it is sent SIGINT, it resumes without having sent the string as stdin to the child process:

^C{:capture=>"", :status=>#<Process::Status: pid 18296 INT (signal 2)>}
[error: 130 (15.000s)]
@yaauie

This comment has been minimized.

Copy link
Author

yaauie commented Apr 2, 2019

@jsvd

This comment has been minimized.

Copy link

jsvd commented Apr 2, 2019

Any chance we can get some eyes here with a bit of urgency @headius ? Seems open3 is broken is more than 1 way on java 11. Here's another we're seeing during installation of logstash in debian buster, reduced to its most basic form:

  • Dockerfile
FROM debian:buster

RUN apt-get update && \
    apt-get install -y zlib1g-dev build-essential vim rake git curl libssl-dev libreadline-dev libyaml-dev  \
      libxml2-dev libxslt-dev openjdk-11-jdk-headless curl iputils-ping netcat && \
    apt-get clean

WORKDIR /root

RUN curl https://repo1.maven.org/maven2/org/jruby/jruby-dist/9.2.6.0/jruby-dist-9.2.6.0-bin.tar.gz | tar -zxf -

WORKDIR /root/jruby-9.2.6.0

CMD ./bin/jruby -ropen3 -e 'Open3.popen3("echo 1") {|stdin, stdout, stderr, wait_thr|  }'
  • Running container after building (docker build --tag=test .):
% docker run -t test 
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by org.jruby.util.SecurityHelper to field java.lang.reflect.Field.modifiers
WARNING: Please consider reporting this to the maintainers of org.jruby.util.SecurityHelper
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
Errno::EBADF: Bad file descriptor - echo
      spawn at org/jruby/RubyProcess.java:1567
      spawn at org/jruby/RubyKernel.java:1632
  popen_run at /root/jruby-9.2.6.0/lib/ruby/stdlib/open3.rb:206
     popen3 at /root/jruby-9.2.6.0/lib/ruby/stdlib/open3.rb:102
     <main> at -e:1

[edit] I should have said please, hopefully didn't come out as any form of demand

@headius

This comment has been minimized.

Copy link
Member

headius commented Apr 3, 2019

We can try to prioritize this. I'll have a chat with @enebo.

@enebo

This comment has been minimized.

Copy link
Member

enebo commented Apr 3, 2019

It is interesting to see if hang on 9 but give a pretty odd error on 11. Seems clear to we are not going native here too.

@headius

This comment has been minimized.

Copy link
Member

headius commented Apr 3, 2019

Some interesting results. Running on MacOS, I'm not having the same issues. The original script hangs on both 9 and 11, and the @jsvd script runs to completion. So there's definitely some platform differences here.

@yaauie

This comment has been minimized.

Copy link
Author

yaauie commented Apr 3, 2019

hang on 9 but give a pretty odd error on 11

The repro in the ticket's description also hangs on JDK11 on Darwin (see threaddump in earlier comment, which was captured on JDK11); @jsvd's issue is likely related in some way, but not the same repro.

@headius

This comment has been minimized.

Copy link
Member

headius commented Apr 3, 2019

@yaauie Yes, I think it's a separate issue.

I have managed to get the original script to run to completion after patching IO.pipe to always use native file descriptors when possible.

I believe the problem here stems from our inability to unwrap the channels given by the JDK Pipe.pipe() call when on Java 9+, due to the module encapsulation. Without those actual descriptors I suspect we're failing to do all the proper subprocess logic to ensure they're wired up to the right places.

diff --git a/core/src/main/java/org/jruby/util/io/PosixShim.java b/core/src/main/java/org/jruby/util/io/PosixShim.java
index a8fe3ab309..fa245a52d0 100644
--- a/core/src/main/java/org/jruby/util/io/PosixShim.java
+++ b/core/src/main/java/org/jruby/util/io/PosixShim.java
@@ -12,6 +12,7 @@ import java.nio.channels.Pipe;
 
 import jnr.constants.platform.Errno;
 import jnr.constants.platform.Fcntl;
+import jnr.enxio.channels.NativeDeviceChannel;
 import jnr.posix.FileStat;
 import jnr.posix.POSIX;
 
@@ -268,18 +269,23 @@ public class PosixShim {
     public Channel[] pipe() {
         clear();
         try {
-            Pipe pipe = Pipe.open();
-            Channel source = pipe.source(), sink = pipe.sink();
-
             if (posix.isNative() && !Platform.IS_WINDOWS) {
-                // set cloexec if possible
-                int read = FilenoUtil.filenoFrom(source);
-                int write = FilenoUtil.filenoFrom(sink);
-                setCloexec(read, true);
-                setCloexec(write, true);
+                int[] readwrite = {-1, -1};
+                if (posix.pipe(readwrite) == 0) {
+                    // set cloexec if possible
+                    int read = readwrite[0];
+                    int write = readwrite[1];
+
+                    setCloexec(read, true);
+                    setCloexec(write, true);
+
+                    return new Channel[]{new NativeDeviceChannel(read), new NativeDeviceChannel(write)};
+                }
             }
 
-            return new Channel[]{source, sink};
+            // JDK logic
+            Pipe pipe  = Pipe.open();
+            return new Channel[]{pipe.source(), pipe.sink()};
         } catch (IOException ioe) {
             errno = Helpers.errnoFromException(ioe);
             return null;
@headius

This comment has been minimized.

Copy link
Member

headius commented Apr 3, 2019

And here we have a Ruby equivalent workaround. It appears that the main issue is being unable to set these file descriptors to close_on_exec, which causes them to be open and appear to be still live in the child process. This results in the hang.

#!/usr/bin/env ruby
require 'open3'

class IO
  def self.pipe
    readwrite = Java::int[2].new
    JRuby.runtime.posix.pipe(readwrite)
    return readwrite.map do |fd|
      io = IO.for_fd(fd)
      io.close_on_exec = true
      io
    end
  end
end

$stderr.puts(RUBY_DESCRIPTION)
capture, status = Open3.capture2('cat', stdin_data: 'hello, world')
$stdout.puts(capture: capture, status: status)

So it's not strictly necessary that we be using true native IO.pipe; we just need to be able to set the descriptor cloexec.

@headius

This comment has been minimized.

Copy link
Member

headius commented Apr 3, 2019

To be more specific...

The sink we have in the parent process feeds into the child process's stdin. In order to let the child process know there's no more input, we close that sink, which shuts down one endpoint for child's stdin. However that same descriptor is still alive in the child, so it's still open, so it never completes execution and cat keeps waiting for input.

@enebo

This comment has been minimized.

Copy link
Member

enebo commented Apr 3, 2019

@headius I confirm that the Java patch works for original reporter script on Linux. Even @jsvd script works for me with that patch.

@kares

This comment has been minimized.

Copy link
Member

kares commented Apr 4, 2019

haven't tried the docker way - but on my Linux its enough to add opens for the sun.nio.ch package :

JRUBY_OPTS="$JRUBY_OPTS -J--add-opens java.base/sun.nio.ch=org.jruby.dist"

and also a patch in modulator ... the full opens needed for JRuby than becomes :

  JAVA_OPTS="$JAVA_OPTS --add-opens java.base/java.io=org.jruby.dist"
  JAVA_OPTS="$JAVA_OPTS --add-opens java.base/java.nio.channels=org.jruby.dist"
  JAVA_OPTS="$JAVA_OPTS --add-opens java.base/sun.nio.ch=org.jruby.dist"

we have the getFD method declared in interface sun.nio.ch.SelChImpl (module: module java.base)
modulator will check for isOpen("sun.nio.ch") but that fails since it isn't open unconditionally yet is open to the org.jruby.dist module - we need to adjust the module checking part to also be able to check against a provided module and all should work as in Java 8.

@kares

This comment has been minimized.

Copy link
Member

kares commented Apr 4, 2019

so we'll need: headius/modulator#1 and than should be able to check open-ness against JRuby's module

@kares

This comment has been minimized.

Copy link
Member

kares commented Apr 4, 2019

also it makes me wonder whether adding such internal opens everywhere (launcher etc) makes sense.
for embedded cases its a bit annoying having to --add-opens java.base/sun.nio.ch=org.jruby.dist
what if we simply tried adding those at runtime (we could extend modulator's API to do that)?

@kares kares added this to the JRuby 9.2.7.0 milestone Apr 4, 2019

@kares

This comment has been minimized.

Copy link
Member

kares commented Apr 4, 2019

and here's what I mean headius/modulator#2

@kares

This comment has been minimized.

Copy link
Member

kares commented Apr 4, 2019

if those modulator updates are in, here's the patch that gets things working :

diff --git a/core/src/main/java/org/jruby/util/io/FilenoUtil.java b/core/src/main/java/org/jruby/util/io/FilenoUtil.java
index 573ca51348..6dc7724738 100644
--- a/core/src/main/java/org/jruby/util/io/FilenoUtil.java
+++ b/core/src/main/java/org/jruby/util/io/FilenoUtil.java
@@ -1,6 +1,6 @@
 package org.jruby.util.io;
 
-import com.headius.backport9.modules.Modules;
+import com.headius.modulator.Modulator;
 import jnr.enxio.channels.NativeSelectableChannel;
 import jnr.posix.FileStat;
 import jnr.posix.POSIX;
@@ -131,13 +131,16 @@ public class FilenoUtil {
 
     private static class ReflectiveAccess {
         static {
+            // open package "sun.nio.ch" (from java.base) for org.jruby.dist module
+            Modulator.addOpens(FileDescriptor.class, "sun.nio.ch", ReflectiveAccess.class);
+
             Method getFD;
             Class selChImpl;
             try {
                 selChImpl = Class.forName("sun.nio.ch.SelChImpl");
                 try {
                     getFD = selChImpl.getMethod("getFD");
-                    if (!Modules.trySetAccessible(getFD)) {
+                    if (!Modulator.trySetAccessible(getFD, ReflectiveAccess.class)) {
                         getFD = null;
                     }
                 } catch (Exception e) {
@@ -156,7 +159,7 @@ public class FilenoUtil {
                 fileChannelImpl = Class.forName("sun.nio.ch.FileChannelImpl");
                 try {
                     fd = fileChannelImpl.getDeclaredField("fd");
-                    if (!Modules.trySetAccessible(fd)) {
+                    if (!Modulator.trySetAccessible(fd, ReflectiveAccess.class)) {
                         fd = null;
                     }
                 } catch (Exception e) {
@@ -172,7 +175,7 @@ public class FilenoUtil {
             Field ffd;
             try {
                 ffd = FileDescriptor.class.getDeclaredField("fd");
-                if (!Modules.trySetAccessible(ffd)) {
+                if (!Modulator.trySetAccessible(ffd, ReflectiveAccess.class)) {
                     ffd = null;
                 }
             } catch (Exception e) {
@@ -187,4 +190,5 @@ public class FilenoUtil {
         private static final Field FILE_CHANNEL_IMPL_FD;
         private static final Field FILE_DESCRIPTOR_FD;
     }
+
 }

@headius headius closed this in 403b29c Apr 5, 2019

@headius

This comment has been minimized.

Copy link
Member

headius commented Apr 8, 2019

Closing the loop: this is all done for 9.2.7. We needed to open up one additional package, sun.nio.ch, and make some enhancements to our module-wrapping library to allow that opening to be seen.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.