A Sunny Commune - Cheng's Blog

Comments on Better Error Messages in Glassfish

This is my comments (expaned and better formatted) on this discussion: Improved Usability and Error Messages. Cay Horstmann first posted this article on this topic.

Cay, great summary. A few comments on "Nested exception is..." section.

When a system exceptin (e.g. NPE in your case) occurred in EJB, the container is required to log it and rethrow a EJBException. This is the nature of any distributed computing. Users really need to look at both client side errors and server side logs. From the client side error (e.g., RemoteException, ServerException, etc), users can know the root cause is at the server side. I'd suggest appclient container print out something like:

"please refer to server.log for server-side errors..."

I feel the same pain every time I see the long stacktrace from appclient container for any errors. They are not well ordered. Normally people would expect the outer-most exceptions first, and the inner-most exceptions last. But from the appclent exceptions I've got, it's hard to tell which one wraps which.

Just as an experiment, I wrote a simple EJB 3 stateless session bean whose business method throws an IllegalStateException.

package hello.ejb;
import javax.ejb.Remote;

@Remote public interface HelloEJBRemote {
    void hello();
}

package hello.ejb;
import javax.ejb.Stateless;

@Stateless public class HelloEJBBean implements HelloEJBRemote {
    public void hello() {
        throw new IllegalStateException("IllegalStateException from hello.");
    }
}

package hello;
import hello.ejb.HelloEJBRemote;
import javax.ejb.EJB;

public class Main {
    @EJB(beanName="HelloEJBBean")
    private static HelloEJBRemote helloEJB;
    
    public static void main(String[] args) {
        helloEJB.hello();
    }    
}

When invoked from application client, I got the following on the client side:

C:\Sun\AppServer\domains\domain1\generated\xml\j2ee-apps\hello>C:\sun\appserver\bin\appclient -client helloClient.jar
Jul 8, 2006 5:01:22 PM com.sun.enterprise.appclient.MainWithModuleSupport 
WARNING: ACC003: Application threw an exception.
javax.ejb.EJBException: nested exception is: java.rmi.ServerException: RemoteException occurred in server thread; nested exception is:
        java.rmi.RemoteException
java.rmi.ServerException: RemoteException occurred in server thread; nested exception is:
        java.rmi.RemoteException
        at com.sun.corba.ee.impl.javax.rmi.CORBA.Util.mapSystemException(Util.java:188)
        at com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.privateInvoke(StubInvocationHandlerImpl.java:172)
        at com.sun.corba.ee.impl.presentation.rmi.StubInvocationHandlerImpl.invoke(StubInvocationHandlerImpl.java:119)
        at com.sun.corba.ee.impl.presentation.rmi.bcel.BCELStubBase.invoke(BCELStubBase.java:197)
        at hello.ejb.__HelloEJBRemote_Remote_DynamicStub.hello(__HelloEJBRemote_Remote_DynamicStub.java)
        at hello.ejb._HelloEJBRemote_Wrapper.hello(hello.ejb._HelloEJBRemote_Wrapper.java)
        at hello.Main.main(Main.java:19)
        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:585)
        at com.sun.enterprise.util.Utility.invokeApplicationMain(Utility.java:232)
        at com.sun.enterprise.appclient.MainWithModuleSupport.(MainWithModuleSupport.java:329)
        at com.sun.enterprise.appclient.Main.main(Main.java:180)
Caused by: java.rmi.RemoteException
        at com.sun.enterprise.iiop.POAProtocolMgr.mapException(POAProtocolMgr.java:234)
        at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1280)
        at com.sun.ejb.containers.EJBObjectInvocationHandler.invoke(EJBObjectInvocationHandler.java:197)
        at com.sun.ejb.containers.EJBObjectInvocationHandlerDelegate.invoke(EJBObjectInvocationHandlerDelegate.java:110)
        at $Proxy30.hello(Unknown Source)
        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:585)
        at com.sun.corba.ee.impl.presentation.rmi.ReflectiveTie._invoke(ReflectiveTie.java:121)
        at com.sun.corba.ee.impl.protocol.CorbaServerRequestDispatcherImpl.dispatchToServant(CorbaServerRequestDispatcherImpl.java:650)
        at com.sun.corba.ee.impl.protocol.CorbaServerRequestDispatcherImpl.dispatch(CorbaServerRequestDispatcherImpl.java:193)
        at com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequestRequest(CorbaMessageMediatorImpl.java:1705)
        at com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:1565)
        at com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleInput(CorbaMessageMediatorImpl.java:947)
        at com.sun.corba.ee.impl.protocol.giopmsgheaders.RequestMessage_1_2.callback(RequestMessage_1_2.java:178)
        at com.sun.corba.ee.impl.protocol.CorbaMessageMediatorImpl.handleRequest(CorbaMessageMediatorImpl.java:717)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.dispatch(SocketOrChannelConnectionImpl.java:473)
        at com.sun.corba.ee.impl.transport.SocketOrChannelConnectionImpl.doWork(SocketOrChannelConnectionImpl.java:1270)
        at com.sun.corba.ee.impl.orbutil.threadpool.ThreadPoolImpl$WorkerThread.run(ThreadPoolImpl.java:479)
javax.ejb.EJBException: nested exception is: java.rmi.ServerException: RemoteException occurred in server thread; nested exception is:
        java.rmi.RemoteException
        at hello.ejb._HelloEJBRemote_Wrapper.hello(hello.ejb._HelloEJBRemote_Wrapper.java)
        at hello.Main.main(Main.java:19)
        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:585)
        at com.sun.enterprise.util.Utility.invokeApplicationMain(Utility.java:232)
        at com.sun.enterprise.appclient.MainWithModuleSupport.(MainWithModuleSupport.java:329)
        at com.sun.enterprise.appclient.Main.main(Main.java:180)
Exception in thread "main" java.lang.RuntimeException: java.lang.reflect.InvocationTargetException
        at com.sun.enterprise.appclient.MainWithModuleSupport.(MainWithModuleSupport.java:340)
        at com.sun.enterprise.appclient.Main.main(Main.java:180)
Caused by: java.lang.reflect.InvocationTargetException
        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:585)
        at com.sun.enterprise.util.Utility.invokeApplicationMain(Utility.java:232)
        at com.sun.enterprise.appclient.MainWithModuleSupport.(MainWithModuleSupport.java:329)
        ... 1 more
Caused by: javax.ejb.EJBException: nested exception is: java.rmi.ServerException: RemoteException occurred in
server thread; nested exception is:
        java.rmi.RemoteException
        at hello.ejb._HelloEJBRemote_Wrapper.hello(hello.ejb._HelloEJBRemote_Wrapper.java)
        at hello.Main.main(Main.java:19)
        ... 7 more

Application is simple: a total of 3 simple classes, no deployment descriptors, no deployment plans. Client-side error message is much longer than all the source code combined.

It seems all these appclient exceptions are chained like this, from outer-most to inner-most:

1. java.lang.RuntimeException
2. java.lang.reflect.InvocationTargetException
3. javax.ejb.EJBException
4. java.rmi.ServerException
5. java.rmi.RemoteException

A general suggestion on logging wrapper exceptions like InvocationTargetException and PrivilegedActionException. IMHO, It adds no value to log them. Just logging their getCause() should be sufficient. Why would a user care if you are using reflection, or doPriv block? These exceptions only expose implementation details, and clutter logs.

For the same reason, I wouldn't rethrow a InvocationTargetException and PrivilegedActionException to the client (caller) code. But I'm less sure about this since appserver is very complex software.

Just my 2 cents.

Posted at 06:26PM Jul 08, 2006 by chengfang in Glassfish  |  Comments[1]