silence_stderr fails trying to create /dev/null

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?

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

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

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

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())

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.

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.

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?

Just did:

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

Same problem

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.

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.

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