SUBSCRIBE/RE-SUBSCRIBE returning 500 Server Internal Error

31 views
Skip to first unread message

Naresh Kumar

unread,
Nov 15, 2013, 4:41:18 PM11/15/13
to mobicent...@googlegroups.com
Hi,

First I would like to thank you for providing an open source SIP platform. I appreciate the work you guys are putting to maintain the code. I am evaluating the Mobicents SIP Presence (MSP) server to integrate with our existing system to provide update for change in status using SIP. We did lots of testing and it worked great. We have an issue with one of the scenario.

Here is the scenario. We have setup a resource list with two entries as given below. A SIP client subscribes to the list using Service URI. Now we delete one of the entry from the list using XCAP. The delete returns successfully and there is no error in MSP yet. But when SUBSCRIBE request is send again to extend the subscription, MSP is throwing TransactionRolledbackLocalException exception caused by NullPointerException and nothing is working after this.

Next if we shut down the SIP client and start again. The SIP client is sending new SUBSCRIBE request. The MSP is throwing the same TransactionRolledbackLocalException exception caused by NullPointerException again. We don't have any way to recover from the bug.

Has anyone experienced this issue? If you fixed the issue, please share the details. Thanks in advance.

Resource List
---------------
<?xml version="1.0" encoding="UTF-8"?><resource-lists xmlns="urn:ietf:params:xml:ns:resource-lists">
<list name="Default">
<entry uri="sip:+17033...@example.com">
<display-name>fuser1</display-name>
</entry>
<entry uri="sip:bo...@example.com" xmlns="urn:ietf:params:xml:ns:resource-lists">
<display-name>Bob Jones</display-name>
</entry>
</list>
</resource-lists>


RLS
-------------
<?xml version="1.0" encoding="UTF-8"?><rls-services xmlns="urn:ietf:params:xml:ns:rls-services">
<service uri="sip:+17033...@example.com">
<resource-list>http://127.0.0.1:8080/mobicents/resource-lists/users/sip:%2B1703...@example.com/index/~~/resource-lists/list%5b@name=%22Default%22%5d</resource-list>
<packages>
<package>presence</package>
</packages>
</service>
</rls-services>

Logs for first Exception
-------------------------
15:02:45,980 INFO [ServerTransactionWrapper] (pool-34-thread-1) ServerTransaction[z9hG4bK-18523-2-3.000000] sending response:
SIP/2.0 200 OK
To: "+17033453619" <sip:+17033...@example.com>;tag=b1359f4a
Via: SIP/2.0/UDP 127.0.0.1:5061;branch=z9hG4bK-18523-2-3.000000
CSeq: 3 SUBSCRIBE
Call-ID: 2-1...@127.0.0.1
From: "+17033452400" <sip:+17033...@example.com>;tag=2
Contact: "Mobicents SIP Event Server" <sip:127.0.0.1:5060>
Expires: 0
Content-Length: 0


15:02:45,986 ERROR [EventRoutingTaskImpl] (pool-34-thread-1) Caught exception while routing EventContext[event type id = EventTypeID[name=javax.sip.Dialog.SUBSCRIBE,vendor=net.java.slee,version=1.2] , event = RequestEventWrapper[ EVENT[SUBSCRIBE] DIALOG[DialogWrapper[ handle = 2-1...@127.0.0.1:b1359f4a:2, state = Confirmed Dialog, clientTXs = [] ]] TX[ServerTransaction[z9hG4bK-18523-2-3.000000]]] , local ac = RA:SipRA:2-1...@127.0.0.1:b1359f4a:2 , address = SIP: "+17033453619" <sip:+17033...@example.com> , serviceID = null]
javax.slee.TransactionRolledbackLocalException: SbbLocalObject Invocation resulted in exception!
at org.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.processInvocationTargetException(SbbLocalObjectInterceptor.java:139)
at org.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.invokeAndReturnObject(SbbLocalObjectInterceptor.java:121)
at org.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.invokeAndReturnvoid(SbbLocalObjectInterceptor.java:154)
at org.mobicents.slee.sipevent.server.subscription.EventListSubscriberSbbLocalObjectImpl.unsubscribe(EventListSubscriberSbbLocalObjectImpl.java)
at org.mobicents.slee.sipevent.server.subscription.eventlist.EventListSubscriptionHandler.removeSubscription(EventListSubscriptionHandler.java:220)
at org.mobicents.slee.sipevent.server.subscription.sip.SipSubscriptionHandler.processRequest(SipSubscriptionHandler.java:230)
at org.mobicents.slee.sipevent.server.subscription.SubscriptionControlSbb.onSubscribeInDialog(SubscriptionControlSbb.java:314)
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.mobicents.slee.runtime.sbbentity.SbbEntityImpl.invokeEventHandler(SbbEntityImpl.java:481)
at org.mobicents.slee.runtime.eventrouter.routingtask.EventRoutingTaskImpl.routeQueuedEvent(EventRoutingTaskImpl.java:379)
at org.mobicents.slee.runtime.eventrouter.routingtask.EventRoutingTaskImpl.run(EventRoutingTaskImpl.java:126)
at org.mobicents.slee.runtime.eventrouter.EventRouterExecutorImpl$EventRoutingTaskStatsCollector.run(EventRouterExecutorImpl.java:73)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:680)
Caused by: java.lang.NullPointerException
at org.mobicents.slee.sipevent.server.rlscache.ResourceList.getEntries(ResourceList.java:412)
at org.mobicents.slee.sipevent.server.rlscache.RLSServiceImpl.getEntries(RLSServiceImpl.java:77)
at org.mobicents.slee.sipevent.server.subscription.eventlist.EventListSubscriberSbb.unsubscribe(EventListSubscriberSbb.java:184)
at org.mobicents.slee.sipevent.server.subscription.eventlist.EventListSubscriberSbb.unsubscribe(EventListSubscriberSbb.java:167)
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.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.invokeAndReturnObject(SbbLocalObjectInterceptor.java:95)
... 16 more
15:02:57,949 INFO [SipResourceAdaptor] (Timer-9) SIP Transaction z9hg4bk-18523-2-2.000000 terminated
15:03:04,445 INFO [AuthenticationProxySbbImpl] (pool-33-thread-1) Skipping authentication for local request.
15:03:04,446 INFO [AuthenticationProxySbbImpl] (pool-33-thread-1) Asserted user: null
15:03:04,446 INFO [AggregationProxySbbImpl] (pool-33-thread-1) get(resourceSelector=resource-lists/users/sip:+17033...@example.com/index,user=null)
15:03:17,983 INFO [SipResourceAdaptor] (Timer-9) SIP Transaction z9hg4bk-18523-2-3.000000 terminated

-------------------------------
Logs for fresh SUBSCRIBE
-------------------------------
15:24:20,438 INFO [SipResourceAdaptor] (SipRA-UDPMessageChannelThread-3) Received Request:
SUBSCRIBE sip:+17033...@example.com SIP/2.0
Via: SIP/2.0/UDP 127.0.0.1:5061;branch=z9hG4bK-18704-1-1.000000
From: "+17033452400" <sip:+17033...@example.com>;tag=1
To: "+17033453619" <sip:+17033...@example.com>
Call-ID: 1-1...@127.0.0.1
CSeq: 1 SUBSCRIBE
Contact: <sip:+17033...@127.0.0.1:5061>
Max-Forwards: 70
Expires: 3600
Event: presence
Supported: eventlist
Accept: application/pidf+xml,application/rlmi+xml,multipart/related,multipart/signed,application/pkcs7
Content-Length: 0


15:24:20,445 INFO [PresenceSubscriptionControl] (pool-31-thread-1) Notifier sip:+17033...@example.com has no ruleset, allowing subscription 1-1...@127.0.0.1:6949774e:1@presence
15:24:20,447 INFO [ServerTransactionWrapper] (pool-31-thread-1) ServerTransaction[z9hG4bK-18704-1-1.000000] sending response:
SIP/2.0 200 OK
To: "+17033453619" <sip:+17033...@example.com>;tag=6949774e
Via: SIP/2.0/UDP 127.0.0.1:5061;branch=z9hG4bK-18704-1-1.000000
CSeq: 1 SUBSCRIBE
Call-ID: 1-1...@127.0.0.1
From: "+17033452400" <sip:+17033...@example.com>;tag=1
Contact: "Mobicents SIP Event Server" <sip:127.0.0.1:5060>
Expires: 3600
Content-Length: 0


15:24:20,452 ERROR [SubscriptionControlSbbImpl] (pool-31-thread-1) Error processing new subscription authorization
javax.slee.TransactionRolledbackLocalException: SbbLocalObject Invocation resulted in exception!
at org.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.processInvocationTargetException(SbbLocalObjectInterceptor.java:139)
at org.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.invokeAndReturnObject(SbbLocalObjectInterceptor.java:121)
at org.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.invokeAndReturnvoid(SbbLocalObjectInterceptor.java:154)
at org.mobicents.slee.sipevent.server.subscription.EventListSubscriberSbbLocalObjectImpl.subscribe(EventListSubscriberSbbLocalObjectImpl.java)
at org.mobicents.slee.sipevent.server.subscription.eventlist.EventListSubscriptionHandler.createSubscription(EventListSubscriptionHandler.java:203)
at org.mobicents.slee.sipevent.server.subscription.sip.NewSipSubscriptionHandler.newSipSubscriptionAuthorization(NewSipSubscriptionHandler.java:313)
at org.mobicents.slee.sipevent.server.subscription.SubscriptionControlSbb.newSubscriptionAuthorization(SubscriptionControlSbb.java:504)
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.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.invokeAndReturnObject(SbbLocalObjectInterceptor.java:95)
at org.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.invokeAndReturnvoid(SbbLocalObjectInterceptor.java:154)
at org.mobicents.slee.sipevent.server.subscription.SubscriptionControlSbbLocalObjectImpl.newSubscriptionAuthorization(SubscriptionControlSbbLocalObjectImpl.java)
at org.mobicents.slee.sippresence.server.subscription.PresenceSubscriptionControl.isSubscriberAuthorized(PresenceSubscriptionControl.java:135)
at org.mobicents.slee.sippresence.server.integrated.subscription.IntegratedSubscriptionControlSbb.isSubscriberAuthorized(IntegratedSubscriptionControlSbb.java:183)
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.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.invokeAndReturnObject(SbbLocalObjectInterceptor.java:95)
at org.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.invokeAndReturnvoid(SbbLocalObjectInterceptor.java:154)
at org.mobicents.slee.sippresence.server.integrated.subscription.IntegratedSubscriptionControlSbbLocalObjectImpl.isSubscriberAuthorized(IntegratedSubscriptionControlSbbLocalObjectImpl.java)
at org.mobicents.slee.sipevent.server.subscription.sip.NewSipSubscriptionHandler.authorizeNewSipSubscription(NewSipSubscriptionHandler.java:200)
at org.mobicents.slee.sipevent.server.subscription.sip.NewSipSubscriptionHandler.newSipSubscription(NewSipSubscriptionHandler.java:142)
at org.mobicents.slee.sipevent.server.subscription.sip.SipSubscriptionHandler.processRequest(SipSubscriptionHandler.java:159)
at org.mobicents.slee.sipevent.server.subscription.SubscriptionControlSbb.onSubscribeOutOfDialog(SubscriptionControlSbb.java:301)
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.mobicents.slee.runtime.sbbentity.SbbEntityImpl.invokeEventHandler(SbbEntityImpl.java:481)
at org.mobicents.slee.runtime.eventrouter.routingtask.EventRoutingTaskImpl.routeQueuedEvent(EventRoutingTaskImpl.java:379)
at org.mobicents.slee.runtime.eventrouter.routingtask.EventRoutingTaskImpl.run(EventRoutingTaskImpl.java:126)
at org.mobicents.slee.runtime.eventrouter.EventRouterExecutorImpl$EventRoutingTaskStatsCollector.run(EventRouterExecutorImpl.java:73)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:895)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:918)
at java.lang.Thread.run(Thread.java:680)
Caused by: java.lang.NullPointerException
at org.mobicents.slee.sipevent.server.rlscache.ResourceList.getEntries(ResourceList.java:412)
at org.mobicents.slee.sipevent.server.rlscache.RLSServiceImpl.getEntries(RLSServiceImpl.java:77)
at org.mobicents.slee.sipevent.server.subscription.eventlist.NotificationData.<init>(NotificationData.java:107)
at org.mobicents.slee.sipevent.server.subscription.eventlist.EventListSubscriberSbb.subscribe(EventListSubscriberSbb.java:100)
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.mobicents.slee.container.deployment.interceptors.SbbLocalObjectInterceptor.invokeAndReturnObject(SbbLocalObjectInterceptor.java:95)
... 36 more
15:24:20,454 WARN [SIPTransaction] (pool-31-thread-1) reparsing original request [B@63f99ae2 since it was eagerly cleaned up, but beware this is not efficient with the aggressive flag set !
15:24:20,455 INFO [ServerTransactionWrapper] (pool-31-thread-1) ServerTransaction[z9hG4bK-18704-1-1.000000] sending response:
SIP/2.0 500 Server Internal Error
To: "+17033453619" <sip:+17033...@example.com>
Via: SIP/2.0/UDP 127.0.0.1:5061;branch=z9hG4bK-18704-1-1.000000
CSeq: 1 SUBSCRIBE
Call-ID: 1-1...@127.0.0.1
From: "+17033452400" <sip:+17033...@example.com>;tag=1
Contact: "Mobicents SIP Event Server" <sip:127.0.0.1:5060>
Content-Length: 0


15:24:27,414 INFO [SipResourceAdaptor] (Timer-9) SIP Transaction z9hg4bk-18700-1-1.000000 terminated

Reply all
Reply to author
Forward
0 new messages