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?

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.

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

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.