Read only archive ; use https://github.com/JacORB/JacORB/issues for new issues
Bug 979 - Unexpected exception on local calls interceptions
Summary: Unexpected exception on local calls interceptions
Status: RESOLVED FIXED
Alias: None
Product: JacORB
Classification: Unclassified
Component: ORB (show other bugs)
Version: 3.4
Hardware: All All
: P5 critical
Assignee: Mailinglist to track bugs
URL:
Depends on:
Blocks:
 
Reported: 2014-04-15 15:04 UTC by Hugo Roenick
Modified: 2014-05-22 08:49 UTC (History)
3 users (show)

See Also:


Attachments
Demo where the error can be reproduced (3.29 KB, application/x-gzip)
2014-04-15 15:04 UTC, Hugo Roenick
Details
Demo with fix in pom.xml (3.42 KB, application/x-gzip)
2014-04-16 06:08 UTC, Hugo Roenick
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Hugo Roenick 2014-04-15 15:04:43 UTC
Created attachment 433 [details]
Demo where the error can be reproduced

I've experienced an unexpected behaviour while implementing a handshake protocol using CORBA interceptors and forward request.

I built a small example to illustrate the problem that I'm experiencing. In this example my protocol defines that the server side will only accepts calls from who attaches a correct secret to requests. If a wrong secret is attached, then the server throws a NO_PERMISSION exception. On the client side, the interceptor knows that if it gets a NO_PERMISSION then he can retry the request attaching the correct secret. Forward Request is used by the client interceptor to retry the request.

In this example the client will call "sayHello" to server, which print the hello message but he will also try to say goodbye, calling "sayGoodbye" to himself (emulating the local call) through a CORBA reference of him self.

Running this demo we can see that the client reaches de server, the server prints the Hello message, but an exception occurs while checking if the CORBA reference to him self does exists.

Here is the output from the server side:

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/Users/hroenick/Development/jacorb/3.4/lib/slf4j-jdk14-1.6.4.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/Users/hroenick/.m2/repository/org/slf4j/slf4j-jdk14/1.6.4/slf4j-jdk14-1.6.4.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
INFO Initialising ORB with ID: 
INFO InterceptorManager started with 1 Server Interceptors, 1 Client Interceptors and 0 IOR Interceptors
INFO oid: 00 01 0F 2D 0B 1F 04 02 0F 2C 1E 28 10 06 30 46 38 14 14 1B ...-.....,.(..0F8...48 4C 1B                                                    HL.object is activated
INFO Using server ID (5631190032) for transient POA
INFO ORB run
INFO Opened new server-side TCP/IP transport to 192.168.0.103:56885
INFO Closed server-side transport to 192.168.0.103:56885
INFO Opened new server-side TCP/IP transport to 192.168.0.103:56886
INFO Closed server-side transport to 192.168.0.103:56886
INFO Opened new server-side TCP/IP transport to 192.168.0.103:56887
INFO Closed server-side transport to 192.168.0.103:56887
INFO Opened new server-side TCP/IP transport to 192.168.0.103:56888
Hello, World!
INFO ClientConnectionManager: created new ClientGIOPConnection to 192.168.0.103:56882 (39b8d6f7)
SEVERE rid: 0 opname: sayHello invocation: throwable was thrown.
java.lang.NullPointerException
	at org.jacorb.orb.Delegate.servant_postinvoke(Delegate.java:2561)
	at org.jacorb.orb.Delegate.non_existent(Delegate.java:2205)
	at org.omg.CORBA.portable.ObjectImpl._non_existent(ObjectImpl.java:61)
	at demo.HelloImpl.sayHello(HelloImpl.java:15)
	at demo.HelloPOA._invoke(HelloPOA.java:54)
	at org.jacorb.poa.RequestProcessor.invokeOperation(RequestProcessor.java:350)
	at org.jacorb.poa.RequestProcessor.process(RequestProcessor.java:672)
	at org.jacorb.poa.RequestProcessor.run(RequestProcessor.java:830)
INFO Closed server-side transport to 192.168.0.103:56888

Is this a bug of JacORB when dealing with local calls?
Comment 1 Hugo Roenick 2014-04-16 06:08:10 UTC
Created attachment 434 [details]
Demo with fix in pom.xml

Updating the demo with corrections in pom.xml
Comment 2 Quynh 2014-05-02 14:40:10 UTC
(In reply to Hugo Roenick from comment #1)
> Created attachment 434 [details]
> Demo with fix in pom.xml
> 
> Updating the demo with corrections in pom.xml

Hi Hugo,

  I think I know what caused the NullPointerException.  In Delegate.non_existent(), the ServantObject was null from the call to servant_preinvoke() below:

    try
    {
        so = servant_preinvoke(self, "_non_existent", java.lang.Object.class);
    }
    catch (OBJECT_NOT_EXIST e)
    {
        return true;
    }

That is because the obj._non_existent() call in sayHello() was made with the "Any wrong secret" credential in sayHello(), and it was rejected by the ServerRequestInterceptorImpl.receive_request() on the server side with the NO_PERMISSION exception which causes servant_preinvoke() to return null for the ServantObject.  The NullPointerException was thrown when it was accessed in the call:

    finally
    {
      servant_postinvoke(self, so);
    }

Since it is a local call, the ForwardRequest exception was passed on instead of the NO_PERMISSION.
 
I think, as an improvement to Delegate.non_existent(), the code segment below can be added check for null ServantObject and throw the OBJ_ADAPTER exception:

     if (so == null )
     {
       throw new OBJ_ADAPTER( "Servant returned from servant_preinvoke was null" );
     }


To make your code to work, I think you need to remove the check for NO_PERMISSION and just forward all exceptions in the ClientRequestInterceptor.receive_exception().

Hope that helps.

Quynh Nguyen
Comment 3 Nick Cross 2014-05-02 14:48:50 UTC
@Quynh : I have a potential fix in https://github.com/rnc/JacORB/tree/BZ979 which Hugo is testing.
Comment 4 Quynh 2014-05-05 11:50:40 UTC
@Nick : I repeated the test with the suggested fix, and it worked.  However, in Delegate.non_existent(), even with wrapping the call to servant_preinvoke() with a while loop, I  still think that you could potentially still get a null servant object because of an unexpected exception or an unknown condition other than the OBJECT_NOT_EXIST exception.
Comment 5 Hugo Roenick 2014-05-06 13:35:57 UTC
Hi, Nick and Quynh.

I run my test with the suggested branch and I keep having the same error. The code lines of the Stack Trace are slightly different, but it appears to be the same error.

@Quynh, have you tested this same attached demo?

@Nick, is it possible that the branch does not contains all the commits?
Comment 6 Hugo Roenick 2014-05-06 13:37:04 UTC
Here is the stack trace:

SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [jar:file:/Users/hroenick/Development/jacorb/Bz979/lib/slf4j-jdk14-1.6.4.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/Users/hroenick/.m2/repository/org/slf4j/slf4j-jdk14/1.7.6/slf4j-jdk14-1.7.6.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
INFO Initialising ORB with ID: 
INFO InterceptorManager started with 1 Server Interceptors, 1 Client Interceptors and 1 IOR Interceptors
INFO oid: 00 01 0F 35 33 4C 4D 19 10 18 48 28 10 06 30 46 38 14 14 1B ...53LM...H(..0F8...48 4C 1B                                                    HL.object is activated
INFO Using server ID (8121910950) for transient POA
INFO Opened new server-side TCP/IP transport to 10.0.64.108:55428
INFO Closed server-side transport to 10.0.64.108:55428
INFO Opened new server-side TCP/IP transport to 10.0.64.108:55429
INFO Closed server-side transport to 10.0.64.108:55429
INFO Opened new server-side TCP/IP transport to 10.0.64.108:55430
INFO Closed server-side transport to 10.0.64.108:55430
INFO Opened new server-side TCP/IP transport to 10.0.64.108:55431
Hello, World!
INFO ClientConnectionManager: created new ClientGIOPConnection to 10.0.64.108:55425 (6860991f)
SEVERE rid: 0 opname: sayHello invocation: throwable was thrown.
java.lang.NullPointerException
	at org.jacorb.orb.Delegate.servant_postinvoke(Delegate.java:2567)
	at org.jacorb.orb.Delegate.non_existent(Delegate.java:2205)
	at org.omg.CORBA.portable.ObjectImpl._non_existent(ObjectImpl.java:61)
	at demo.HelloImpl.sayHello(HelloImpl.java:15)
	at demo.HelloPOA._invoke(HelloPOA.java:54)
	at org.jacorb.poa.RequestProcessor.invokeOperation(RequestProcessor.java:350)
	at org.jacorb.poa.RequestProcessor.process(RequestProcessor.java:672)
	at org.jacorb.poa.RequestProcessor.run(RequestProcessor.java:830)
INFO Closed server-side transport to 10.0.64.108:55431
Comment 7 Hugo Roenick 2014-05-06 13:46:05 UTC
Just realize what I did wrong. Please forget about my last 2 comments. Will redo the test.
Sorry about that.
Comment 8 Hugo Roenick 2014-05-07 08:13:53 UTC
Just tested the correction and it did work! =)
Comment 9 Nick Cross 2014-05-22 08:48:52 UTC
Fixed by SHA 374532c99fe64e214192f49d56a9530079924acd