JRuby

Weird replacement of STDOUT by /dev/null

Details

  • Type: Bug Bug
  • Status: Closed Closed
  • Priority: Major Major
  • Resolution: Incomplete
  • Affects Version/s: None
  • Fix Version/s: None
  • Component/s: None
  • Labels:
    None
  • Environment:
    # jruby --version
    jruby 1.4.0 (ruby 1.8.7 patchlevel 174) (2009-12-14 943d51c) (Java HotSpot(TM) 64-Bit Server VM 1.6.0_16) [amd64-java]
  • Number of attachments :
    0

Description

A long running rails metal over jruby application using glassfish "stopped" suddenly. Well, it did not quite stop, but it stopped doing output (and some parts of the app stopped to, but this is not diagnosable, as output stopped).

The observation is that filedescriptor #1 (stdout) does not point to the log file (as initially redirected), but to /dev/null. Note that this filedescriptor does not appear to be simply closed, but somehow closed-and-replaced.

It happens on a multi-threading app running on 2 cores which does about 100'000'000 "puts" statements and needs a week's running time on average until this issue appears, but then it is there. It has happened twice so far, on different machines.

Activity

Ascending order - Click to sort in descending order
Hide
Permalink
Charles Oliver Nutter added a comment -

This sounds very much like some library (possibly rails itself) reopening stdout to /dev/null to supress logging for a short time and then putting it back...except that something goes wrong when it tries to put it back. Can you grep your libraries for /dev/null and see if you get any hits? I will do the same here.

Show
Charles Oliver Nutter added a comment - This sounds very much like some library (possibly rails itself) reopening stdout to /dev/null to supress logging for a short time and then putting it back...except that something goes wrong when it tries to put it back. Can you grep your libraries for /dev/null and see if you get any hits? I will do the same here.
Hide
Permalink
Charles Oliver Nutter added a comment -

Here's all cases where something reopens stdout or stderr using /dev/null. I'm guessing one of these has a race where it's saving the old stdout into a global location that gets destroyed in a multithreaded environment.

lib/ruby/gems/1.8/gems/activesupport-2.1.2/lib/active_support/core_ext/kernel/reporting.rb:38:    stream.reopen(RUBY_PLATFORM =~ /mswin/ ? 'NUL:' : '/dev/null')
lib/ruby/gems/1.8/gems/activesupport-2.1.2/lib/active_support/core_ext/process/daemon.rb:15:        STDIN.reopen "/dev/null"       # Free file descriptors and
lib/ruby/gems/1.8/gems/activesupport-2.1.2/lib/active_support/core_ext/process/daemon.rb:16:        STDOUT.reopen "/dev/null", "a" # point them somewhere sensible.
lib/ruby/gems/1.8/gems/activesupport-2.1.2/lib/active_support/core_ext/process/daemon.rb:17:        STDERR.reopen '/dev/null', 'a'
lib/ruby/gems/1.8/gems/activesupport-2.3.5/lib/active_support/core_ext/kernel/reporting.rb:38:    stream.reopen(RUBY_PLATFORM =~ /mswin/ ? 'NUL:' : '/dev/null')
lib/ruby/gems/1.8/gems/activesupport-2.3.5/lib/active_support/core_ext/process/daemon.rb:15:        STDIN.reopen "/dev/null"       # Free file descriptors and
lib/ruby/gems/1.8/gems/activesupport-2.3.5/lib/active_support/core_ext/process/daemon.rb:16:        STDOUT.reopen "/dev/null", "a" # point them somewhere sensible.
lib/ruby/gems/1.8/gems/activesupport-2.3.5/lib/active_support/core_ext/process/daemon.rb:17:        STDERR.reopen '/dev/null', 'a'
lib/ruby/gems/1.8/gems/erubis-2.6.5/benchmark/bench.rb:304:  ## open /dev/null
lib/ruby/gems/1.8/gems/erubis-2.6.5/benchmark/bench.rb:305:  $stdout = File.open('/dev/null', 'w')
lib/ruby/gems/1.8/gems/mail-2.1.2/lib/tasks/corpus.rake:39:    $stderr.reopen("/dev/null", "w")
lib/ruby/gems/1.8/gems/rack-1.0.0/bin/rackup:163:    STDIN.reopen "/dev/null"
lib/ruby/gems/1.8/gems/rack-1.0.0/bin/rackup:164:    STDOUT.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rack-1.0.0/bin/rackup:165:    STDERR.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rack-1.0.1/bin/rackup:163:    STDIN.reopen "/dev/null"
lib/ruby/gems/1.8/gems/rack-1.0.1/bin/rackup:164:    STDOUT.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rack-1.0.1/bin/rackup:165:    STDERR.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rack-1.1.0/lib/rack/server.rb:199:          STDIN.reopen "/dev/null"
lib/ruby/gems/1.8/gems/rack-1.1.0/lib/rack/server.rb:200:          STDOUT.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rack-1.1.0/lib/rack/server.rb:201:          STDERR.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rails-2.3.5/dispatches/gateway.cgi:38:    STDIN.reopen "/dev/null"
lib/ruby/gems/1.8/gems/rails-2.3.5/dispatches/gateway.cgi:39:    STDOUT.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rails-2.3.5/lib/tasks/testing.rake:33:    STDERR.reopen(RUBY_PLATFORM =~ /(:?mswin|mingw)/ ? 'NUL:' : '/dev/null')
lib/ruby/gems/1.8/gems/railties-3.0.0.beta/lib/rails/test_unit/testing.rake:33:    STDERR.reopen(RUBY_PLATFORM =~ /(:?mswin|mingw)/ ? 'NUL:' : '/dev/null')
lib/ruby/gems/1.8/gems/sinatra-0.9.4/test/server_test.rb:28:    $stdout = File.open('/dev/null', 'wb')
lib/ruby/gems/1.8/gems/webrat-0.7.0/lib/webrat/selenium/silence_stream.rb:9:          stream.reopen(RUBY_PLATFORM =~ /mswin/ ? 'NUL:' : '/dev/null')
Show
Charles Oliver Nutter added a comment - Here's all cases where something reopens stdout or stderr using /dev/null. I'm guessing one of these has a race where it's saving the old stdout into a global location that gets destroyed in a multithreaded environment. 
lib/ruby/gems/1.8/gems/activesupport-2.1.2/lib/active_support/core_ext/kernel/reporting.rb:38:    stream.reopen(RUBY_PLATFORM =~ /mswin/ ? 'NUL:' : '/dev/null')
lib/ruby/gems/1.8/gems/activesupport-2.1.2/lib/active_support/core_ext/process/daemon.rb:15:        STDIN.reopen "/dev/null"       # Free file descriptors and
lib/ruby/gems/1.8/gems/activesupport-2.1.2/lib/active_support/core_ext/process/daemon.rb:16:        STDOUT.reopen "/dev/null", "a" # point them somewhere sensible.
lib/ruby/gems/1.8/gems/activesupport-2.1.2/lib/active_support/core_ext/process/daemon.rb:17:        STDERR.reopen '/dev/null', 'a'
lib/ruby/gems/1.8/gems/activesupport-2.3.5/lib/active_support/core_ext/kernel/reporting.rb:38:    stream.reopen(RUBY_PLATFORM =~ /mswin/ ? 'NUL:' : '/dev/null')
lib/ruby/gems/1.8/gems/activesupport-2.3.5/lib/active_support/core_ext/process/daemon.rb:15:        STDIN.reopen "/dev/null"       # Free file descriptors and
lib/ruby/gems/1.8/gems/activesupport-2.3.5/lib/active_support/core_ext/process/daemon.rb:16:        STDOUT.reopen "/dev/null", "a" # point them somewhere sensible.
lib/ruby/gems/1.8/gems/activesupport-2.3.5/lib/active_support/core_ext/process/daemon.rb:17:        STDERR.reopen '/dev/null', 'a'
lib/ruby/gems/1.8/gems/erubis-2.6.5/benchmark/bench.rb:304:  ## open /dev/null
lib/ruby/gems/1.8/gems/erubis-2.6.5/benchmark/bench.rb:305:  $stdout = File.open('/dev/null', 'w')
lib/ruby/gems/1.8/gems/mail-2.1.2/lib/tasks/corpus.rake:39:    $stderr.reopen("/dev/null", "w")
lib/ruby/gems/1.8/gems/rack-1.0.0/bin/rackup:163:    STDIN.reopen "/dev/null"
lib/ruby/gems/1.8/gems/rack-1.0.0/bin/rackup:164:    STDOUT.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rack-1.0.0/bin/rackup:165:    STDERR.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rack-1.0.1/bin/rackup:163:    STDIN.reopen "/dev/null"
lib/ruby/gems/1.8/gems/rack-1.0.1/bin/rackup:164:    STDOUT.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rack-1.0.1/bin/rackup:165:    STDERR.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rack-1.1.0/lib/rack/server.rb:199:          STDIN.reopen "/dev/null"
lib/ruby/gems/1.8/gems/rack-1.1.0/lib/rack/server.rb:200:          STDOUT.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rack-1.1.0/lib/rack/server.rb:201:          STDERR.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rails-2.3.5/dispatches/gateway.cgi:38:    STDIN.reopen "/dev/null"
lib/ruby/gems/1.8/gems/rails-2.3.5/dispatches/gateway.cgi:39:    STDOUT.reopen "/dev/null", "a"
lib/ruby/gems/1.8/gems/rails-2.3.5/lib/tasks/testing.rake:33:    STDERR.reopen(RUBY_PLATFORM =~ /(:?mswin|mingw)/ ? 'NUL:' : '/dev/null')
lib/ruby/gems/1.8/gems/railties-3.0.0.beta/lib/rails/test_unit/testing.rake:33:    STDERR.reopen(RUBY_PLATFORM =~ /(:?mswin|mingw)/ ? 'NUL:' : '/dev/null')
lib/ruby/gems/1.8/gems/sinatra-0.9.4/test/server_test.rb:28:    $stdout = File.open('/dev/null', 'wb')
lib/ruby/gems/1.8/gems/webrat-0.7.0/lib/webrat/selenium/silence_stream.rb:9:          stream.reopen(RUBY_PLATFORM =~ /mswin/ ? 'NUL:' : '/dev/null')
Hide
Permalink
Charles Oliver Nutter added a comment -

Oh, and by "all cases" I mean "all cases in my installed gems". This certainly isn't an exhaustive list.

Show
Charles Oliver Nutter added a comment - Oh, and by "all cases" I mean "all cases in my installed gems". This certainly isn't an exhaustive list.
Hide
Permalink
Charles Oliver Nutter added a comment -

No follow-up in several months...I'm not sure where to go with this, so if you want to reopen it please provide a way to reproduce it.

Show
Charles Oliver Nutter added a comment - No follow-up in several months...I'm not sure where to go with this, so if you want to reopen it please provide a way to reproduce it.

People

Vote (0)
Watch (1)

Dates

  • Created:
    Updated:
    Resolved:
Atlassian JIRA (v4.4.3#663-r165197) | Report a problem
Powered by a free Atlassian JIRA open source license for Codehaus. Try JIRA - bug tracking software for your team.