JRuby

silence_stderr fails trying to create /dev/null

Details

  • Type: Bug Bug
  • Status: Closed Closed
  • Priority: Major Major
  • Resolution: Fixed
  • Affects Version/s: JRuby 1.1RC2
  • Fix Version/s: JRuby 1.1RC3
  • Component/s: Extensions
  • Labels:
    None
  • Environment:
    OpenSolaris (snv_79b, SXDE 1/08)
  • Number of attachments :
    0

Description

I was trying to follow http://blogs.sun.com/arungupta/entry/totd_24_getting_started_with, adjusted for RC2.

$ jruby script/server
/export/home/notroot/jruby-1.1RC2/lib/ruby/gems/1.8/gems/activesupport-2.0.2/lib/active_support/core_ext/kernel/reporting.rb:26:in `silence_stderr': Permission denied (IOError)
from /export/home/notroot/jruby-1.1RC2/lib/ruby/gems/1.8/gems/activesupport-2.0.2/lib/active_support/core_ext/kernel/reporting.rb:26
from /export/home/notroot/jruby-1.1RC2/lib/ruby/gems/1.8/gems/rails-2.0.2/lib/commands/server.rb:20:in `require'
from /export/home/notroot/jruby-1.1RC2/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:27:in `require'
from script/server:3

Using truss, I found that just before the Permission Denied error it tried to create /dev/null (rather than simply open it).

2856/2: open64("/dev/null", O_RDWR|O_CREAT|O_EXCL, 0666) Err#13 EACCES [ALL]
/export/home/notroot/jruby-1.1RC2/lib/ruby/gems/1.8/gems/activesupport-2.0.2/lib/active_support/core_ext/kernel/reporting.rb:26:in `silence_stderr'

From open(2):

O_EXCL

If O_CREAT and O_EXCL are set, open() fails if the file
exists. The check for the existence of the file and the
creation of the file if it does not exist is atomic with
respect to other threads executing open() naming the
same filename in the same directory with O_EXCL and
O_CREAT set. If O_EXCL and O_CREAT are set, and path
names a symbolic link, open() fails and sets errno to
EEXIST, regardless of the contents of the symbolic link.
If O_EXCL is set and O_CREAT is not set, the result is
undefined.

Activity

Hide
Charles Oliver Nutter added a comment -

I am starting to wonoder if the fix for this and for other /dev/null and NUL: related bugs is to revert to the NullWritableChannel we used before. I had hoped that Channels opened on /dev/null and NUL: would behave correctly, but perhaps they are not.

Mike, can you boil this down to a single piece of code that fails in JRuby and passes in regular Ruby?

Show
Charles Oliver Nutter added a comment - I am starting to wonoder if the fix for this and for other /dev/null and NUL: related bugs is to revert to the NullWritableChannel we used before. I had hoped that Channels opened on /dev/null and NUL: would behave correctly, but perhaps they are not. Mike, can you boil this down to a single piece of code that fails in JRuby and passes in regular Ruby?
Hide
Charles Oliver Nutter added a comment -

This is very probably fixed by recent changes. Can you try again? I just committed a few more fixes myself.

Show
Charles Oliver Nutter added a comment - This is very probably fixed by recent changes. Can you try again? I just committed a few more fixes myself.
Hide
Mike Gerdts added a comment -

I just checked out the latest code around 19:10 27 Feb 2008 CST.

Checkout and build procedure was:

$ svn co http://svn.codehaus.org/jruby/trunk/jruby
$ cd jruby
$ ant

The problem seems to persist.

800/2: stat64("/dev/null", 0xD0AA48F0) = 0
800/2: stat64("/dev/null", 0xD0AA48F0) = 0
800/2: open64("/dev/null", O_RDWR|O_CREAT|O_EXCL, 0666) Err#13 EACCES [ALL]
/export/home/notroot/jruby/lib/ruby/gems/1.8/gems/activesupport-2.0.2/lib/active_support/core_ext/kernel/reporting.rb:26:in `silence_stream'800/2: write(2, " / e x p o r t / h o m e".., 141) = 141
: Permission denied800/2: write(2, " : P e r m i s s i o n".., 19) = 19
(IOError)
800/2: write(2, " ( I O E r r o r )\n", 11) = 11
from /export/home/notroot/jruby/lib/ruby/gems/1.8/gems/activesupport-2.0.2/lib/active_support/core_ext/kernel/reporting.rb:26:in `silence_stderr'
800/2: write(2, "\t f r o m / e x p o r".., 148) = 148
from /export/home/notroot/jruby/lib/ruby/gems/1.8/gems/rails-2.0.2/lib/commands/server.rb:20
800/2: write(2, "\t f r o m / e x p o r".., 95) = 95

Without truss:

$ jruby script/server
/export/home/notroot/jruby/lib/ruby/gems/1.8/gems/activesupport-2.0.2/lib/active_support/core_ext/kernel/reporting.rb:26:in `silence_stream': Permission denied (IOError)
from /export/home/notroot/jruby/lib/ruby/gems/1.8/gems/activesupport-2.0.2/lib/active_support/core_ext/kernel/reporting.rb:26:in `silence_stderr'
from /export/home/notroot/jruby/lib/ruby/gems/1.8/gems/rails-2.0.2/lib/commands/server.rb:20
from /export/home/notroot/jruby/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:27:in `require'
from /export/home/notroot/jruby/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:27:in `require'
from script/server:3

Show
Mike Gerdts added a comment - I just checked out the latest code around 19:10 27 Feb 2008 CST. Checkout and build procedure was: $ svn co http://svn.codehaus.org/jruby/trunk/jruby $ cd jruby $ ant The problem seems to persist. 800/2: stat64("/dev/null", 0xD0AA48F0) = 0 800/2: stat64("/dev/null", 0xD0AA48F0) = 0 800/2: open64("/dev/null", O_RDWR|O_CREAT|O_EXCL, 0666) Err#13 EACCES [ALL] /export/home/notroot/jruby/lib/ruby/gems/1.8/gems/activesupport-2.0.2/lib/active_support/core_ext/kernel/reporting.rb:26:in `silence_stream'800/2: write(2, " / e x p o r t / h o m e".., 141) = 141 : Permission denied800/2: write(2, " : P e r m i s s i o n".., 19) = 19 (IOError) 800/2: write(2, " ( I O E r r o r )\n", 11) = 11 from /export/home/notroot/jruby/lib/ruby/gems/1.8/gems/activesupport-2.0.2/lib/active_support/core_ext/kernel/reporting.rb:26:in `silence_stderr' 800/2: write(2, "\t f r o m / e x p o r".., 148) = 148 from /export/home/notroot/jruby/lib/ruby/gems/1.8/gems/rails-2.0.2/lib/commands/server.rb:20 800/2: write(2, "\t f r o m / e x p o r".., 95) = 95 Without truss: $ jruby script/server /export/home/notroot/jruby/lib/ruby/gems/1.8/gems/activesupport-2.0.2/lib/active_support/core_ext/kernel/reporting.rb:26:in `silence_stream': Permission denied (IOError) from /export/home/notroot/jruby/lib/ruby/gems/1.8/gems/activesupport-2.0.2/lib/active_support/core_ext/kernel/reporting.rb:26:in `silence_stderr' from /export/home/notroot/jruby/lib/ruby/gems/1.8/gems/rails-2.0.2/lib/commands/server.rb:20 from /export/home/notroot/jruby/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:27:in `require' from /export/home/notroot/jruby/lib/ruby/site_ruby/1.8/rubygems/custom_require.rb:27:in `require' from script/server:3
Hide
Mike Gerdts added a comment -

Using a bit of dtrace, I can stop the process when it tries to create /dev/null. In one window (as root):

  1. dtrace -w -n 'syscall::open64:entry / execname == "java" && copyinstr(arg0) == "/dev/null" / { stop(); }'
    dtrace: description 'syscall::open64:entry ' matched 1 probe
    dtrace: allowing destructive actions

In another window as another user:

$ jruby script/server

After several seconds, in a third window:

$ pstack `pgrep java`
...
----------------- lwp# 2 / thread# 2 --------------------
d12b5be5 __open64 (8165d08, 502, 1b6) + 15
d12a2c13 open64 (8165d08, 502, 1b6) + 72
d09421f6 sysOpen (8165d08, 502, 1b6) + 3a
d0c45125 JVM_Open (8165d08, 502, 1b6) + 3d
d0898590 Java_java_io_UnixFileSystem_createFileExclusively (80700ec, d0a9fa88, d0a9fa84, ce9ac6fb, d0a9faf8, d0a9fa54) + 64
ce80a08b * java/io/UnixFileSystem.createFileExclusively(Ljava/lang/String;)Z+0
ce802cb1 * java/io/File.createNewFile()Z+23
ce802cb1 * org/jruby/util/io/ChannelStream.freopen(Ljava/lang/String;Lorg/jruby/util/io/ModeFlags;)V+122
ce8033b9 * org/jruby/RubyIO.reopen([Lorg/jruby/runtime/builtin/IRubyObject;)Lorg/jruby/runtime/builtin/IRubyObject;+799
ce802d77 * org/jruby/RubyIOInvoker$reopen_method_1_1.call(Lorg/jruby/runtime/ThreadContext;Lorg/jruby/runtime/builtin/IRubyObject;L
org/jruby/RubyModule;Ljava/lang/String;[Lorg/jruby/runtime/builtin/IRubyObject;)Lorg/jruby/runtime/builtin/IRubyObject;+39
...

Show
Mike Gerdts added a comment - Using a bit of dtrace, I can stop the process when it tries to create /dev/null. In one window (as root):
  1. dtrace -w -n 'syscall::open64:entry / execname == "java" && copyinstr(arg0) == "/dev/null" / { stop(); }' dtrace: description 'syscall::open64:entry ' matched 1 probe dtrace: allowing destructive actions
In another window as another user: $ jruby script/server After several seconds, in a third window: $ pstack `pgrep java` ... ----------------- lwp# 2 / thread# 2 -------------------- d12b5be5 __open64 (8165d08, 502, 1b6) + 15 d12a2c13 open64 (8165d08, 502, 1b6) + 72 d09421f6 sysOpen (8165d08, 502, 1b6) + 3a d0c45125 JVM_Open (8165d08, 502, 1b6) + 3d d0898590 Java_java_io_UnixFileSystem_createFileExclusively (80700ec, d0a9fa88, d0a9fa84, ce9ac6fb, d0a9faf8, d0a9fa54) + 64 ce80a08b * java/io/UnixFileSystem.createFileExclusively(Ljava/lang/String;)Z+0 ce802cb1 * java/io/File.createNewFile()Z+23 ce802cb1 * org/jruby/util/io/ChannelStream.freopen(Ljava/lang/String;Lorg/jruby/util/io/ModeFlags;)V+122 ce8033b9 * org/jruby/RubyIO.reopen([Lorg/jruby/runtime/builtin/IRubyObject;)Lorg/jruby/runtime/builtin/IRubyObject;+799 ce802d77 * org/jruby/RubyIOInvoker$reopen_method_1_1.call(Lorg/jruby/runtime/ThreadContext;Lorg/jruby/runtime/builtin/IRubyObject;L org/jruby/RubyModule;Ljava/lang/String;[Lorg/jruby/runtime/builtin/IRubyObject;)Lorg/jruby/runtime/builtin/IRubyObject;+39 ...
Hide
Mike Gerdts added a comment -

src/org/jruby/RubyIO.java

506 } else {
507 // TODO: This is an freopen in MRI, this is close, but not quite the same
508 openFile.getMainStream().freopen(path, getIOModes(getRuntime(), openFile.getModeAsString(getRuntime())));
509

openFile.getModeAsString returns "ab+". getIOModes sets the create flag.

src/org/jruby/util/io/ChannelStream.java

818 if (modes.isCreate()) {
819 if (theFile.exists() && modes.isExclusive()) { 820 throw getRuntime().newErrnoEEXISTError("File exists - " + path); 821 }
822 theFile.createNewFile();

As such, we will always find our way into the code above. As such, if the file exists it will either get a File exists exception or createNewFile() will fail.

There seems to be a need for some code to open an existing file for appending.

Show
Mike Gerdts added a comment - src/org/jruby/RubyIO.java 506 } else { 507 // TODO: This is an freopen in MRI, this is close, but not quite the same 508 openFile.getMainStream().freopen(path, getIOModes(getRuntime(), openFile.getModeAsString(getRuntime()))); 509 openFile.getModeAsString returns "ab+". getIOModes sets the create flag. src/org/jruby/util/io/ChannelStream.java 818 if (modes.isCreate()) { 819 if (theFile.exists() && modes.isExclusive()) { 820 throw getRuntime().newErrnoEEXISTError("File exists - " + path); 821 } 822 theFile.createNewFile(); As such, we will always find our way into the code above. As such, if the file exists it will either get a File exists exception or createNewFile() will fail. There seems to be a need for some code to open an existing file for appending.
Hide
Masaki Katakai added a comment -

I also encountered this issue on both SXDE 1/08 SPARC and x86.

Show
Masaki Katakai added a comment - I also encountered this issue on both SXDE 1/08 SPARC and x86.
Hide
Charles Oliver Nutter added a comment -

Can those of you seeing this problem try it with JRuby trunk? We recently reverted some code that tried to access /dev/null directly and replaced it with code that simulated /dev/null by accepting byte writes and not doing anything. This should resolve most issues with /dev/null.

The bottom-line issue seems to be that the JDK/JVM isn't as flexible about opening/dealing with /dev/null as normal libc functions are.

Please update with comments based on JRuby trunk. We're looking at pushing out JRuby 1.1 RC3 this week.

Show
Charles Oliver Nutter added a comment - Can those of you seeing this problem try it with JRuby trunk? We recently reverted some code that tried to access /dev/null directly and replaced it with code that simulated /dev/null by accepting byte writes and not doing anything. This should resolve most issues with /dev/null. The bottom-line issue seems to be that the JDK/JVM isn't as flexible about opening/dealing with /dev/null as normal libc functions are. Please update with comments based on JRuby trunk. We're looking at pushing out JRuby 1.1 RC3 this week.
Hide
Masaki Katakai added a comment -

Hi Charles, how are you?

I tried trunk just now but it's still not working for me. The same error happens. How about you, Mike?

Show
Masaki Katakai added a comment - Hi Charles, how are you? I tried trunk just now but it's still not working for me. The same error happens. How about you, Mike?
Hide
Mike Gerdts added a comment -

Just did:

$ svn update
$ ant clean
$ ant
$ bin/jruby hello/script/server

Same problem

Show
Mike Gerdts added a comment - Just did: $ svn update $ ant clean $ ant $ bin/jruby hello/script/server Same problem
Hide
Charles Oliver Nutter added a comment -

Ok, I have not been able to reproduce, but I did find a path through reopen that would actually try to open /dev/null, which it seems on OpenSolaris it should not try to do. I have a few questions:

  • Could you please try with a revision later than r6118 and see if the problem has gone away?
  • Could you try with normal Ruby? I could not see that we're doing anything different from Ruby...it seems that perhaps the combination of that reopen line and OpenSolaris permissions on /dev/null may be to blame.

Please reopen if the problem still exists.

Show
Charles Oliver Nutter added a comment - Ok, I have not been able to reproduce, but I did find a path through reopen that would actually try to open /dev/null, which it seems on OpenSolaris it should not try to do. I have a few questions:
  • Could you please try with a revision later than r6118 and see if the problem has gone away?
  • Could you try with normal Ruby? I could not see that we're doing anything different from Ruby...it seems that perhaps the combination of that reopen line and OpenSolaris permissions on /dev/null may be to blame.
Please reopen if the problem still exists.
Hide
Masaki Katakai added a comment -

Great! I tried just now and it works without problem. I tried native ruby (bundled in Solaris) before on SXDE 1/08 and I remember it worked fine.

Show
Masaki Katakai added a comment - Great! I tried just now and it works without problem. I tried native ruby (bundled in Solaris) before on SXDE 1/08 and I remember it worked fine.
Hide
Masaki Katakai added a comment -

I tried it with 1.1RC3 release and I verified it works now.

Show
Masaki Katakai added a comment - I tried it with 1.1RC3 release and I verified it works now.

People

Vote (1)
Watch (2)

Dates

  • Created:
    Updated:
    Resolved: