NPE while routing EventContext with no SBBs attached to AC

[vilpan]

Hello all,
I'm having trouble resolving an exception rising from
EventRoutingTaskImpl.

Scenario:
SBB receives an initial event and detaches itself from the
ActivityContext. In the very same event handler SBB gets a new
activity and attaches itself to the new activity's AC. When an event
is fired on the activity that SBB has detached from (it was the only
SBB attached to the AC) an NPE is caught:
2010-07-07 17:59:24,871 ERROR
[org.mobicents.slee.runtime.eventrouter.routingtask.EventRoutingTaskImpl]
(pool-16-thread-1) Caught exception while routing EventContext[...]
java.lang.NullPointerException
at
org.mobicents.slee.runtime.eventrouter.routingtask.EventRoutingTaskImpl.routeQueuedEvent(EventRoutingTaskImpl.java:
248)
at
org.mobicents.slee.runtime.eventrouter.routingtask.EventRoutingTaskImpl.run(EventRoutingTaskImpl.java:
103)
at org.mobicents.slee.runtime.eventrouter.EventRouterExecutorImpl
$EventRoutingTaskStatsCollector.run(EventRouterExecutorImpl.java:51)
at java.util.concurrent.ThreadPoolExecutor
$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor
$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:619)


Not quite sure at the moment if this could be an issue or am I
misunderstanding something or just doing something wrong. In any case
any hints would be highly appreciated.

Using mobicents 2.1.1.GA on Windows XP Professional SP3.

TIA,
vilpan

[vilpan]

Sorry, forgot to mention the exception from then on starts to loop
indefinitely along with

2010-07-07 17:59:24,871 ERROR

[org.mobicents.slee.runtime.eventrouter.routingtask.HandleSbbRollback]
(pool-16-thread-1) Illegal State! Only one of sbbEntity or SbbObject
can be specified

though no events are generated anymore.

[WozZa XiNg]

Make sure you are on the latest 2.1.1GA release?

vilpan wrote:
> Windows XP Professional SP3.
It runs better on Red Had Linux!

[Eduardo Martins]

Hi, can you provide us a test case project that we can run to see the
issue happening?

-- Eduardo

-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-
http://emmartins.blogspot.com
http://www.redhat.com/solutions/telco

[Eduardo Martins]

Looking at code, if the activity is gone when the event routing starts
this error could happen, since it tries to log something on a null
object, anyway before applying any kind of fix I'm more interested in
understanding how you managed to have an event on a non existent
activity so please share us your app code or ideally a test project.

-- Eduardo

-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-
http://emmartins.blogspot.com
http://www.redhat.com/solutions/telco

[vilpan]

Hi, Eduardo,
I understand the importance of a minimal test case to reproduce an
issue in tracking it down, though I'm afraid it's not easy in this
case as the behaviour was noticed using a custom RA in our local
testing environment. I think it's best to try reproduce the described
scenario using some standard RA or facility and a trivial SBB.

Regarding your statement "to have an event on a non existent
activity", the event is fired when the activity is still alive and
usable. RA successfully fires the event to SLEE and afterwards ends
the activity via SleeEnpoint (with flag
REQUEST_PROCESSING_SUCCESSFUL_CALLBACK) after that the aforementioned
exceptions start looping. The activity and it's handle are not removed
from RAs maps until eventProcessingSuccessful is received -
getActivity and getActivityHandle are usable and it should be possible
to process the event. The essence of the situation I was trying to
describe is that the Activity Context has 0 SBBs attached after the
only attached SBB detaches itself.

As I said, it might not be easy to provide you with the exact test
case, though I'm ready to do additional testing and provide you with
any diagnostic info you see useful.


Thanks,
vilpan

On Jul 8, 11:04 am, Eduardo Martins <emmart...@gmail.com> wrote:
> Looking at code, if the activity is gone when the event routing starts
> this error could happen, since it tries to log something on a null
> object, anyway  before applying any kind of fix I'm more interested in
> understanding how you managed to have an event on a non existent
> activity so please share us your app code or ideally a test project.
>
> -- Eduardo
>

> -:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-http://emmartins.blogspot.comhttp://www.redhat.com/solutions/telco

>
> On Thu, Jul 8, 2010 at 8:59 AM, Eduardo Martins <emmart...@gmail.com> wrote:
> > Hi, can you provide us a test case project that we can run to see the
> > issue happening?
>
> > -- Eduardo
>
> > -:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-
> >http://emmartins.blogspot.com
> >http://www.redhat.com/solutions/telco
>

[Eduardo Martins]

Thinking a bit on possible causes, can you show me your ActivityHandle
impl code? A bad implementation of hashCode() or equals(Object) could
result in a bad relation between the handle and the internal
representation of the activity, the ActivityContext object.

-- Eduardo

-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-
http://emmartins.blogspot.com
http://www.redhat.com/solutions/telco

[vilpan]

Here is the ActivityHandle implementation for the activity in
question. hashCode() and equals are not overridden in other classes.

public class ConnectionActivityHandle implements
javax.slee.resource.ActivityHandle {
private JccConnection connection;

public ConnectionActivityHandle(JccConnection connection) {
this.connection = connection;
}

public boolean equals(Object other) {
if (other != null && other.getClass() == this.getClass()) {
ConnectionActivityHandle cmp = (ConnectionActivityHandle) other;
return cmp.connection == this.connection ||
cmp.connection.equals(this.connection);
}
else {
return false;
}
}

public int hashCode() {
return connection.hashCode();

}
}

On Jul 8, 1:32 pm, Eduardo Martins <emmart...@gmail.com> wrote:
> Thinking a bit on possible causes, can you show me your ActivityHandle
> impl code? A bad implementation of hashCode() or equals(Object) could
> result in a bad relation between the handle and the internal
> representation of the activity, the ActivityContext object.
>
> -- Eduardo
>

> -:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-http://emmartins.blogspot.comhttp://www.redhat.com/solutions/telco
>

[Eduardo Martins]

What about JccConnection?

Also, can you recreate the error with debug log level and send it to me?

-- Eduardo

-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-
http://emmartins.blogspot.com
http://www.redhat.com/solutions/telco

[vilpan]

Sorry for the delay - was forced to shift away my attention due to
some urgent issues.

JccConnection does not provide implementations of hashCode or equals
if that's what you were asking.

I've reproduced the error with debug level enabled and sent you (the e-
mail provided in your profile) the log as I think it's unwieldy to
post here even the excerpt that I think is relevant.

Thanks!

On Jul 8, 5:59 pm, Eduardo Martins <emmart...@gmail.com> wrote:
> What about JccConnection?
>
> Also, can you recreate the error with debug log level and send it to me?
>
> -- Eduardo
>

> -:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-http://emmartins.blogspot.comhttp://www.redhat.com/solutions/telco
>

[Eduardo Martins]

If JccConnection does not implements hashcode and equals then the
ActivityHandle contract is broken, 2 instances of the same
JccConnection will not result in same handle, for instance if you
store the connection or the related ACI in a CMP and later retrieve it
(there is a instance cloning involved in this) then hashcode and
equals matching will fail, since with respect to JccConnection, what
is compared is the java.lang.Object hashcode and equals. Now I'm not
saying this is the reason for the issue but lets first fix it to find
out if it's the cause or not... Let me know if the issue persists.

Then, looking at your log:

1) DISCONNECTED event is fired
2) Activity is ended
3) DISCONNECTED event is routed
4) ActivityEndEvent is routed
5) DISCONNECTED event is routed again

5) is of course the reason of this mess, while you fix the handle I
will try to find out how can this happen. Whatever is the issue reason
the container must be protected from it, I will leave the container
code untouched till we understand exactly why this is happening.

-- Eduardo

-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-
http://emmartins.blogspot.com
http://www.redhat.com/solutions/telco

[Eduardo Martins]

FYI I finally was able to replicate the issue and a fix is proposed,
once a tck run is made and confirms it's good it will be committed.
This should be done tomorrow.

See http://code.google.com/p/mobicents/issues/detail?id=1617 , the
patch is there if you wish to test it before is committed.

But you still should fix your activity handle hashcode and equals, for
instance using using instead a connection id, or some unpredictable
behavior can happen, and it's always not clear where it comes from.
Also, if you want the best performance, I recommend you to check if
there is a transaction and in such case using instead the transacted
methods to fire event and end the activity.

-- Eduardo

-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-
http://emmartins.blogspot.com
http://www.redhat.com/solutions/telco

[vilpan]

This is a work in progress, therefore the lousy (or plain invalid)
implementation of ActivityHandles, but thanks for a good explanation
of the trouble I was trying to get into. :)

Thanks a lot for all of your assistance and, of course, the patch. :)
I guess it'll take quite some time to see the fix in a release. Would
you recommend applying the patch in the issue manually or to try
building the head revision once it's committed?

Could you please elaborate on the aspect of performance gain when
using transactions? I thought current logic is not sophisticated
enough to require transactions and I didn't know it might provide
considerable impact on performance. Are there any other cases where
you would strongly recommend using transactional API alternatives?
What are the cases when non-transactional ones should be preferred?

On Jul 12, 2:41 am, Eduardo Martins <emmart...@gmail.com> wrote:
> FYI I finally was able to replicate the issue and a fix is proposed,
> once a tck run is made and confirms it's good it will be committed.
> This should be done tomorrow.
>

> Seehttp://code.google.com/p/mobicents/issues/detail?id=1617, the

> patch is there if you wish to test it before is committed.
>
> But you still should fix your activity handle hashcode and equals, for
> instance using using instead a connection id, or some unpredictable
> behavior can happen, and it's always not clear where it comes from.
> Also, if you want the best performance, I recommend you to check if
> there is a transaction and in such case using instead the transacted
> methods to fire event and end the activity.
>
> -- Eduardo
>

> -:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-http://emmartins.blogspot.comhttp://www.redhat.com/solutions/telco

>
> On Sun, Jul 11, 2010 at 10:07 AM, Eduardo Martins <emmart...@gmail.com> wrote:
> > If JccConnection does not implements hashcode and equals then the
> > ActivityHandle contract is broken, 2 instances of the same
> > JccConnection will not result in same handle, for instance if you
> > store the connection or the related ACI in a CMP and later retrieve it
> > (there is a instance cloning involved in this) then hashcode and
> > equals matching will fail, since with respect to JccConnection, what
> > is compared is the java.lang.Object hashcode and equals. Now I'm not
> > saying this is the reason for the issue but lets first fix it to find
> > out if it's the cause or not... Let me know if the issue persists.
>
> > Then, looking at your log:
>
> > 1) DISCONNECTED event is fired
> > 2) Activity is ended
> > 3) DISCONNECTED event is routed
> > 4) ActivityEndEvent is routed
> > 5) DISCONNECTED event is routed again
>
> >  5) is of course the reason of this mess, while you fix the handle I
> > will try to find out how can this happen. Whatever is the issue reason
> > the container must be protected from it, I will leave the container
> > code untouched till we understand exactly why this is happening.
>
> > -- Eduardo
>
> > -:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-:-
> >http://emmartins.blogspot.com
> >http://www.redhat.com/solutions/telco
>

[Eduardo Martins]

On Mon, Jul 12, 2010 at 8:00 AM, vilpan <vilius.p...@stud.ktu.lt> wrote:
> This is a work in progress, therefore the lousy (or plain invalid)
> implementation of ActivityHandles, but thanks for a good explanation
> of the trouble I was trying to get into. :)
>
> Thanks a lot for all of your assistance and, of course, the patch. :)
> I guess it'll take quite some time to see the fix in a release. Would
> you recommend applying the patch in the issue manually or to try
> building the head revision once it's committed?

Patch committed. Build it manually, "ant" in
svn/trunk/servers/jain-slee/release, or wait for next build (1105)
done by Hudson server at
http://hudson.jboss.org/hudson/job/MobicentsSlee/

> Could you please elaborate on the aspect of performance gain when
> using transactions? I thought current logic is not sophisticated
> enough to require transactions and I didn't know it might provide
> considerable impact on performance. Are there any other cases where
> you would strongly recommend using transactional API alternatives?
> What are the cases when non-transactional ones should be preferred?

Whenever you have a tx context and use a non-transactional method then
Mobicents container has to go around the tx, this is mandated by JAIN
SLEE 1.1 spec. This means that if you know for sure there is a tx it's
preferable to use the transactional methods. Anyway this is a blind
shot, was just alerting about this curious behavior, performance must
be measured, sometimes the gains are not important so perhaps leave
such optimizations to the end.

-- Eduardo

[vilpan]

Actually, I didn't have enough patience so I've applied the patch
manually and built activities*.jar using maven. I'm not able to
reproduce the issue anymore, I'd call it fixed. :)

Thanks,
vilpan

On Jul 12, 5:09 pm, Eduardo Martins <emmart...@gmail.com> wrote:

> On Mon, Jul 12, 2010 at 8:00 AM, vilpan <vilius.paneve...@stud.ktu.lt> wrote:
> > This is a work in progress, therefore the lousy (or plain invalid)
> > implementation of ActivityHandles, but thanks for a good explanation
> > of the trouble I was trying to get into. :)
>
> > Thanks a lot for all of your assistance and, of course, the patch. :)
> > I guess it'll take quite some time to see the fix in a release. Would
> > you recommend applying the patch in the issue manually or to try
> > building the head revision once it's committed?
>
> Patch committed. Build it manually, "ant" in
> svn/trunk/servers/jain-slee/release, or wait for next build (1105)

> done by Hudson server athttp://hudson.jboss.org/hudson/job/MobicentsSlee/