JRuby Tomcat/Crash

rogergue · March 15, 2010, 11:42am

Hi,

I have a lot of the following entries in localhost.log. Has anyone an
idea how to narrow down the cause of the problem ?

BTW: I use Tomcat 6 and JRuby 1.4

Regards
Roger

SCHWERWIEGEND: Application Error
file:/C:/Program Files (x86)/Apache Software Foundation/Tomcat
6.0/webapps/WEB-Client/WEB-INF/lib/jruby-rack-0.9.5.jar!/jruby/rack/response.rb:29:in
respond': undefined method[]’ for nil:NilClass (NoMethodError)
from :1
…internal jruby stack elided…
from JRuby::Rack::Response.respond(:1)
from (unknown).(unknown)(:1)
15.03.2010 08:46:12 org.apache.catalina.core.ApplicationContext log
SCHWERWIEGEND: Application Error
file:/C:/Program Files (x86)/Apache Software Foundation/Tomcat
6.0/webapps/WEB-Client/WEB-INF/lib/jruby-rack-0.9.5.jar!/jruby/rack/response.rb:29:in
respond': undefined method[]’ for nil:NilClass (NoMethodError)
from :1
…internal jruby stack elided…
from JRuby::Rack::Response.respond(:1)
from (unknown).(unknown)(:1)

and after that I get:

5.03.2010 08:49:16 org.apache.catalina.core.ApplicationContext log
SCHWERWIEGEND: Application Error
java.lang.NullPointerException
at com.sun.jna.Structure.write(Structure.java:561)
at com.sun.jna.Function.convertArgument(Function.java:410)
at com.sun.jna.Function.invoke(Function.java:206)
at com.sun.jna.Library$Handler.invoke(Library.java:204)
at $Proxy0.stat(Unknown Source)
at
org.jruby.ext.posix.BaseNativePOSIX.stat(BaseNativePOSIX.java:184)
at org.jruby.RubyFileTest.directory_p(RubyFileTest.java:84)
at org.jruby.RubyFileTest.directory_p(RubyFileTest.java:74)
at
org.jruby.RubyFileTest$s_method_1_0$RUBYINVOKER$directory_p.call(org/jruby/RubyFileTest$s_method_1_0$RUBYINVOKER$directory_p.gen)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:147)
at org.jruby.ast.CallOneArgNode.interpret(CallOneArgNode.java:57)
at org.jruby.ast.IfNode.interpret(IfNode.java:111)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:136)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:153)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:107)
at org.jruby.ast.CallNoArgNode.interpret(CallNoArgNode.java:61)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.EvStrNode.interpret(EvStrNode.java:86)
at org.jruby.ast.DStrNode.appendToString(DStrNode.java:86)
at org.jruby.ast.DStrNode.buildDynamicString(DStrNode.java:76)
at org.jruby.ast.DStrNode.interpret(DStrNode.java:68)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:173)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:169)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:147)
at org.jruby.ast.FCallOneArgNode.interpret(FCallOneArgNode.java:36)
at
org.jruby.ast.AttrAssignTwoArgNode.interpret(AttrAssignTwoArgNode.java:36)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at
org.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:317)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:268)
at org.jruby.runtime.Block.yield(Block.java:194)
at org.jruby.RubyArray.eachCommon(RubyArray.java:1635)
at org.jruby.RubyArray.each(RubyArray.java:1642)
at
org.jruby.RubyArray$i_method_0_0$RUBYFRAMEDINVOKER$each.call(org/jruby/RubyArray$i_method_0_0$RUBYFRAMEDINVOKER$each.gen)
at
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:116)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:123)
at
org.jruby.ast.CallNoArgBlockNode.interpret(CallNoArgBlockNode.java:64)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
at
org.jruby.internal.runtime.methods.InterpretedMethod.call(InterpretedMethod.java:155)
at
org.jruby.internal.runtime.methods.DefaultMethod.call(DefaultMethod.java:161)
at
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:116)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:123)
at org.jruby.RubyClass$SpecificArityNew.call(RubyClass.java:698)
at
org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:168)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:107)
at org.jruby.ast.CallNoArgNode.interpret(CallNoArgNode.java:61)
at org.jruby.ast.InstAsgnNode.interpret(InstAsgnNode.java:95)
at org.jruby.ast.OpAsgnOrNode.interpret(OpAsgnOrNode.java:105)
at org.jruby.ast.NewlineNode.interpret(NewlineNode.java:104)
at
org.jruby.runtime.InterpretedBlock.evalBlockBody(InterpretedBlock.java:317)
at
org.jruby.runtime.InterpretedBlock.yield(InterpretedBlock.java:268)
at org.jruby.runtime.Block.yield(Block.java:194)
at
org.jruby.libraries.ThreadLibrary$Mutex.synchronize(ThreadLibrary.java:167)
at
org.jruby.libraries.ThreadLibrary$Mutex$i_method_0_0$RUBYINVOKER$synchronize.call(org/jruby/libraries/ThreadLibrary$Mutex$i_method_0_0$RUBYINVOKER$synchronize.gen)
at
org.jruby.runtime.callsite.CachingCallSite.callBlock(CachingCallSite.java:116)
at
org.jruby.runtime.callsite.CachingCallSite.call(CachingCallSite.java:123)

and than:

5.03.2010 08:49:16 org.apache.catalina.core.ApplicationContext log
SCHWERWIEGEND: Error: Couldn’t handle error
java.lang.NullPointerException
at org.jruby.RubyModule.defineAnnotatedMethod(RubyModule.java:795)
at org.jruby.RubyModule.defineAnnotatedMethod(RubyModule.java:762)
at
org.jruby.anno.TypePopulator$DefaultTypePopulator.populate(TypePopulator.java:54)
at
org.jruby.RubyModule.defineAnnotatedMethodsIndividually(RubyModule.java:679)
at org.jruby.RubyModule.defineAnnotatedMethods(RubyModule.java:581)
at
org.jruby.rack.input.RackBaseInput.getClass(RackBaseInput.java:36)
at
org.jruby.rack.input.RackBaseInput.getRackBaseInputClass(RackBaseInput.java:42)
at
org.jruby.rack.input.RackRewindableInput.getRackRewindableInputClass(RackRewindableInput.java:42)
at
org.jruby.rack.input.RackRewindableInput.(RackRewindableInput.java:65)
at
org.jruby.rack.DefaultRackApplication.createRackInput(DefaultRackApplication.java:72)
at
org.jruby.rack.DefaultRackApplication.call(DefaultRackApplication.java:37)
at
org.jruby.rack.servlet.DefaultServletDispatcher.handleException(DefaultServletDispatcher.java:65)
at
org.jruby.rack.servlet.DefaultServletDispatcher.process(DefaultServletDispatcher.java:39)
at org.jruby.rack.RackFilter.doFilter(RackFilter.java:55)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286)
at
org.apache.coyote.http11.Http11AprProcessor.process(Http11AprProcessor.java:857)
at
org.apache.coyote.http11.Http11AprProtocol$Http11ConnectionHandler.process(Http11AprProtocol.java:565)
at
org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1509)
at java.lang.Thread.run(Unknown Source)

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email

rogergue · March 15, 2010, 12:08pm

Hi Roger,

Looks like JNA-related failure to me. One way to solve this is
probably to disable the native support, like this:

jruby -J-Djruby.native.enabled=false …

This is for launching JRuby standalone. For in-container settings, you
might need to adjust them somehow differently. The main thing is to
supply jruby.native.enabled property to the JVM, with value ‘false’.

Alternatively, you could try out the latest 1.5.0.dev builds, chances
are that the problem is fixed there already, since in 1.5 we’ve moved
from JNA to JNR (java native runtime) for native functions.

Latest 1.5.0.dev snapshots are here: http://ci.jruby.org/snapshots/

Thanks,
–Vladimir

On Mon, Mar 15, 2010 at 11:41 AM, Roger G. [email protected]
wrote:

SCHWERWIEGEND: Application Error
6.0/webapps/WEB-Client/WEB-INF/lib/jruby-rack-0.9.5.jar!/jruby/rack/response.rb:29:in
SCHWERWIEGEND: Application Error
org.jruby.RubyFileTest$s_method_1_0$RUBYINVOKER$directory_p.call(org/jruby/RubyFileTest$s_method_1_0$RUBYINVOKER$directory_p.gen)
at
at
at org.jruby.runtime.Block.yield(Block.java:194)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:168)
at
and than:
at org.jruby.RubyModule.defineAnnotatedMethods(RubyModule.java:581)
org.jruby.rack.DefaultRackApplication.call(DefaultRackApplication.java:37)
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email

rogergue · March 15, 2010, 1:40pm

Hi,

thanks for the reply. I added -Djruby.native.enabled=false to
CATALINA_OPTS. But I still keep getting entries in my localhost.log
file.
Is it possible that the log entries are not related to the freeze of the
application ?

The strange part is, that we had no problems (and no entries in
localhost.log) on my development machine and on the test machine. Only
the production system shows this kind of problems. So far we had 3
application freezes the last 2 days.

Regards
Roger

SCHWERWIEGEND: Error: Couldn’t handle error: response committed
org/apache/catalina/connector/OutputBuffer.java:358:in realWriteBytes': org.apache.catalina.connector.ClientAbortException: null (NativeException) from org/apache/tomcat/util/buf/ByteChunk.java:434:influshBuffer’
from org/apache/tomcat/util/buf/ByteChunk.java:349:in append' from org/apache/catalina/connector/OutputBuffer.java:381:inwriteBytes’
from org/apache/catalina/connector/OutputBuffer.java:370:in write' from org/apache/catalina/connector/CoyoteOutputStream.java:89:inwrite’
from org/apache/catalina/connector/CoyoteOutputStream.java:83:in
write' from file:/C:/Program Files (x86)/Apache Software Foundation/Tomcat 6.0/webapps/WEB-Client/WEB-INF/lib/jruby-stdlib-1.4.0.jar!/META-INF/jruby.home/lib/ruby/1.8/logger.rb:580:inwrite_body’
from C:/Program Files (x86)/Apache Software Foundation/Tomcat
6.0/webapps/WEB-Client/WEB-INF/gems/gems/actionpack-2.3.4/lib/action_controller/response.rb:152:in
call' ... 8 levels... from file:/C:/Program Files (x86)/Apache Software Foundation/Tomcat 6.0/webapps/WEB-Client/WEB-INF/lib/jruby-rack-0.9.5.jar!/jruby/rack/response.rb:71:inwrite_body’
from file:/C:/Program Files (x86)/Apache Software Foundation/Tomcat
6.0/webapps/WEB-Client/WEB-INF/lib/jruby-rack-0.9.5.jar!/jruby/rack/response.rb:34:in
`respond’
from :1
…internal jruby stack elided…
from
org.apache.tomcat.util.buf.ByteChunk.flushBuffer(ByteChunk.java:434)
from
org.apache.tomcat.util.buf.ByteChunk.append(ByteChunk.java:349)
from
org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:381)
from
org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:370)

SCHWERWIEGEND: Application Error
6.0/webapps/WEB-Client/WEB-INF/lib/jruby-rack-0.9.5.jar!/jruby/rack/response.rb:29:in
SCHWERWIEGEND: Application Error
org.jruby.RubyFileTest$s_method_1_0$RUBYINVOKER$directory_p.call(org/jruby/RubyFileTest$s_method_1_0$RUBYINVOKER$directory_p.gen)
at
at
at org.jruby.runtime.Block.yield(Block.java:194)
at org.jruby.ast.BlockNode.interpret(BlockNode.java:71)
org.jruby.internal.runtime.methods.DynamicMethod.call(DynamicMethod.java:168)
at
and than:
at org.jruby.RubyModule.defineAnnotatedMethods(RubyModule.java:581)
org.jruby.rack.DefaultRackApplication.call(DefaultRackApplication.java:37)
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at

To unsubscribe from this list, please visit:
 http://xircles.codehaus.org/manage_email

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email

rogergue · March 15, 2010, 8:35pm

On Mon, Mar 15, 2010 at 6:40 AM, Roger G. [email protected] wrote:

thanks for the reply. I added Â -Djruby.native.enabled=false to
CATALINA_OPTS. But I still keep getting entries in my localhost.log file.
Is it possible that the log entries are not related to the freeze of the
application ?

Are you getting exactly the same errors, or new ones?

The strange part is, that we had no problems (and no entries in
localhost.log) on my development machine and on the test machine. Only the
production system shows this kind of problems. So far we had 3 application
freezes the last 2 days.

The error you posted (“response committed”) tells me that either
jruby-rack or Tomcat have already committed the response bytes to the
stream, and then something in Ruby-land (perhaps Rails or Rack) tries
to rewind or roll back the request. Do you have any other errors that
go along with this one, perhaps something that’s causing the request
to bail out?

Charlie

To unsubscribe from this list, please visit:

http://xircles.codehaus.org/manage_email

rogergue · March 15, 2010, 8:54pm

Are you getting exactly the same errors, or new ones?

The same ones

The error you posted (“response committed”) tells me that either
jruby-rack or Tomcat have already committed the response bytes to the
stream, and then something in Ruby-land (perhaps Rails or Rack) tries
to rewind or roll back the request. Do you have any other errors that
go along with this one, perhaps something that’s causing the request
to bail out?

There are some error messages in the production.log. (undefined method
â€˜eachâ€™ for nil:NilClass), but they are unreproducible so far.

Regards
Roger