Java Native Exception logging

Hello,
I’m fairly new to JRuby, so pardon me if this has been covered before,
but I’m working on integrating a Rack app
(jruby-core-1.5.6+jruby-rack-1.0.5) with some java code into a warbler’s
WAR deployed on GlassFishv3 and I’m having trouble getting Java Native
Exception thrown but not handled by the JRuby layer to be logged on the
server side.

I tried setting:

jruby.rack.logging
slf4j

but that doesn’t seem to work although I have slf4j working from the
Java side.

If I manually log the exception in Java before throwing to JRuby it
seems to go through (1) a JRuby stack and then (2) the RackFilter:
java.lang.RuntimeException: This is an exception
at com.mycompany.Simple.testCase1(Simple.java:31)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at
org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling(JavaMethod.java:508)
[…]
at
org.jruby.javasupport.JavaEmbedUtils$1.callMethod(JavaEmbedUtils.java:143)
at
org.jruby.rack.DefaultRackApplication.__call(DefaultRackApplication.java:68)
at
org.jruby.rack.DefaultRackApplication.call(DefaultRackApplication.java:42)
at
org.jruby.rack.DefaultRackDispatcher.process(DefaultRackDispatcher.java:29)
at org.jruby.rack.RackFilter.doFilter(RackFilter.java:63)

I tried plugging my own ServletFilter before the RackFilter to catch and
log exceptions, but the exception doesn’t seem to propagate outside of
the RackFilter’s scope, so somewhere in between it appears to be
consumed… by who?

I looked at the RackFilter.doFilter code and it doesn’t seem to
try/catch anything, so the exception looks consumed within the JRuby
stack?

I looked at
org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling and
it seems to wrap Exceptions into RaiseException and rethrow…

JavaCallable.handleThrowable states // This point is only reached if
there was an exception handler installed
Is there a way to configure a custom exception handler in JRuby?

I’m basically looking for a way to ensure any Exception not caught in
ruby code is reported in the server.log.
Any suggestion?
Thank you!
Cyril

Hi Cyril,

On Fri, Feb 18, 2011 at 11:23 AM, Cyril B. [email protected]
wrote:

jruby.rack.logging
slf4j

but that doesn’t seem to work although I have slf4j working from the
Java side.

That could be a bug. I added custom logging a while back but I myself
haven’t used it heavily and haven’t heard of others using it. You
might look in the server logs for “Error loading logger:” along with a
stacktrace that might give more information. The fallback is
System.out when it is unable to create a logger, so you might have to
look around if the server captures standard output to a different
file.

at
at org.jruby.rack.RackFilter.doFilter(RackFilter.java:63)
org.jruby.javasupport.JavaMethod.invokeDirectWithExceptionHandling and
it seems to wrap Exceptions into RaiseException and rethrow…

JavaCallable.handleThrowable states // This point is only reached if
there was an exception handler installed
Is there a way to configure a custom exception handler in JRuby?

I’m basically looking for a way to ensure any Exception not caught in
ruby code is reported in the server.log.

The DefaultRackDispatcher class is catching every exception and
logging it 1, so that’s why you won’t see them. I could add some
configuration to allow you to turn off its exception handling, but
instead I’d like to see if you can get to the bottom of the logger
configuration issue.

/Nick

Hi Nick, thank you for your feedback.
I’m not seeing any “Error loading logger” errors in our logs.
stdout is redirected to the container log and JRuby’s puts do show up
fine, but setting jruby.rack.logging=stdout ctx param doesn’t seem to
change anything…
I do see the line below in the container log, but the format is
unfamiliar to any of our own log formatters and it does not print the
Java stack trace, which is critical:

2011-02-23T15:26:35-0800 ERROR (orig:NativeException)
java.lang.RuntimeException: This is an exception

It’s coming through our Java Logging Handler where the source cannot be
traced (so possibly JRuby), but again this date format is not like JLA,
Log4j nor Log4r. Does this date format look familiar to jruby-rack?
If so, any idea how the message format can be customized to print the
stack trace?
If not, do you have any suggestion on how I could debug why I’m not
getting jruby-rack logs?
Thanks!
Cyril

On Feb 23, 2011, at 17:45 , Cyril B. wrote:

Hi Nick, thank you for your feedback.
I’m not seeing any “Error loading logger” errors in our logs.
stdout is redirected to the container log and JRuby’s puts do show up fine, but
setting jruby.rack.logging=stdout ctx param doesn’t seem to change anything…
I do see the line below in the container log, but the format is unfamiliar to
any of our own log formatters and it does not print the Java stack trace, which is
critical:

2011-02-23T15:26:35-0800 ERROR (orig:NativeException)
java.lang.RuntimeException: This is an exception

It’s coming through our Java Logging Handler where the source cannot be traced
(so possibly JRuby), but again this date format is not like JLA, Log4j nor Log4r.
Does this date format look familiar to jruby-rack?
If so, any idea how the message format can be customized to print the stack
trace?
If not, do you have any suggestion on how I could debug why I’m not getting
jruby-rack logs?

I don’t recognize the timestamp either. As far as debugging, you’ll
probably have to get more hands-on with the source code. I would suggest
checking out a copy of JRuby-Rack source, loading it up in your Java IDE
of choice, setting some breakpoints and figuring out what’s going on.

/Nick