Skip to main content

SIP performance testing

26 replies [Last post]
ivelin
Offline
Joined: 2003-07-13
Points: 0

Branching off from the multi-threading discussion. SIP performance testing of the Mobicents SIP stack (SLEE,SIP A, SIP Services) justifies a top level discussion.
http://forums.java.net/jive/thread.jspa?messageID=19801&tstart=0#19801

Nijjie8 posted examples. Creating a wiki page from it would be useful.

If leondo can post his initial performance results, that would be a good place to start and improve from there.

Ivein

Reply viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.
torosvi
Offline
Joined: 2005-07-20
Points: 0

Hi!

I have implemented a CLI:
https://mobicents.dev.java.net/issues/show_bug.cgi?id=59
http://wiki.java.net/bin/view/Communications/MobicentsCLI

I had some problems with the -deactivateRaEntity operation and the -activateRaEntity operation just after using -deactivateRaEntity due to the Sip RA. I explain it better in the following thread:

http://forums.java.net/jive/thread.jspa?threadID=14197&tstart=15

I'm going to give you the links to the patch files:
https://mobicents.dev.java.net/nonav/issues/showattachment.cgi/49/SipRes...
https://mobicents.dev.java.net/nonav/issues/showattachment.cgi/38/Resour...

I would like to know if I can commit these changes to the CVS.

Ivelin has told me something about a leak problem. Is this the reason of the commented line in the SipResourceAdaptor?

Line 403:
//this.scanTransaction = new ScanTransaction(this);

Regards,

Victor

leondo
Offline
Joined: 2005-01-18
Points: 0

>ivelin has told me something about a leak problem. Is this >the reason of the commented line in the SipResourceAdaptor?

>Line 403:
>//this.scanTransaction = new ScanTransaction(this);

When you run with JainSipApi1.1, then you need to have this method otherwise it will be leaking.

With JainSipApi1.2, I guess you don't need it because you can register transactionTerminated callback with the SipProvider. I never try this so I cann't answer whether it works or not

ivelin
Offline
Joined: 2003-07-13
Points: 0

JSIP 1.2 funtionality has been available in CVS for some time. I am seing transactionTerminated event handlers in SipResourceAdaptor, but it puzzles me why the ScanTransaction code was not removed altogether.

Fran, can you comment?

leondo
Offline
Joined: 2005-01-18
Points: 0

Hello,

I kicked off the run on the 4 cpu processors machine and I have seen some problems. Most of them are the old problems that I mentioned before:

1. The memory leaks in Service.childObj. The convergence names and sbb entity ids are stored in this map.

2. Calls lost. Some activity context once attached to the SBB entities was no longer attached. I mentioned in the above earlier (post 18). I don't have the knowledge in this area so having someone to look here would be the major milestone.

3. Runtime exception during the cache sync up and transaction timeout (see http://forums.java.net/jive/thread.jspa?threadID=1145&tstart=0 for more info. Can someone tell me how to increase the timeout value for acquiring the lock just for testing? Look like 1 second is not enough.

log for this:
Caused by: java.lang.RuntimeException: Could not store into cache

at org.mobicents.slee.runtime.SbbEntity$PrepareAction.execute(SbbEntity.java:256)

at org.mobicents.slee.runtime.transaction.TxSyncAction.executeActions(TxSyncAction.java:119)

... 14 more

Caused by: javax.transaction.SystemException: upgrade lock for /sbbentity:7729940bcba5c985:704baa:105853cd2bc:-7e1f could not be acquired after 1000 ms. Lock map ownership Read lock owners: []
Write lock owner: :2949
(caller=:2951)

at org.mobicents.slee.runtime.transaction.TransactionManagerImpl.putObject(TransactionManagerImpl.java:687)

at org.mobicents.slee.runtime.Cacheable.putObjectInCache(Cacheable.java:96)

at org.mobicents.slee.runtime.SbbEntity.storeToCache(SbbEntity.java:472)

at org.mobicents.slee.runtime.SbbEntity$PrepareAction.execute(SbbEntity.java:250)

... 15 more

thanks

Leon Do

fram
Offline
Joined: 2004-05-13
Points: 0

Regarding point 3 you can increase the value of the timeout by modifying the following file "xml/jboss-treecache-runtime-service.xml".

1000

I will take a look at the other issues.

Francesco

fram
Offline
Joined: 2004-05-13
Points: 0

Leon,
I'm working on the issue that you are addressing in your post. Lately there has been a lot of confusion about the Proxy Service can you please let me know which version of the Proxy are you using (CallID or ActivityContext as the convergence name)?
Francesco

leondo
Offline
Joined: 2005-01-18
Points: 0

Francesco,

I used Activity Context as the service's convergence name. By the way, I think the memory leaks are due to the lock timeout. The lock timeout happened normally on the ActivityEndEvent during storing of cache which then left objects in the service.childObj hashmap unclean. I don't know whether this can cause call losing problem, may be?

thanks
Leon Do

ivelin
Offline
Joined: 2003-07-13
Points: 0

I just finished reading the SIP scalability paper by the Columnia University. Many thanks to Ranga for pointing it out.
http://www.cs.columbia.edu/techreports/cucs-011-04.pdf

I highly recommend it if you need a practical introduction to the subject as I did. It gave me a good understanding of why we are going for the right failover architecture in the SIP HA Demo.
http://wiki.java.net/bin/view/Communications/MobicentsHADemo

Ivelin

ivelin
Offline
Joined: 2003-07-13
Points: 0

To provide some target for our SIP performance enhancements, I tried to find SIPP test results for other SIP servers.

What I found was that Asterisk is around 20 caps (calls per second).
http://lists.digium.com/pipermail/asterisk-users/2004-May/046387.html

I did not find sipp results for sipd, but the forementioned paper suggests that sipd can handle around 300 caps on a Sun Netra XI (500MHz UltraSparc II w/ 127MB of memory).

Ivelin

leondo
Offline
Joined: 2005-01-18
Points: 0

FYI, I kicked off the run again today and it seem to run much smoother and faster. I was able to pass cumulatively over 300 calls as compare 10-20 previously. Nevertheless, there is still a problem with the synchronization issue around 200 OK (This is where the ActivityContext receive EndActivityEvent and SBB entity is possibly getting destroyed). Hopefully Francesco would be able to add NullActivity for SBB as he mentioned earlier.

Leon Do

leondo
Offline
Joined: 2005-01-18
Points: 0

All,

I submitted the changes that fixed calls being lost after a short run. The problem was somewhere between the NIST stack and the RA.

After received 200 OK for the BYE, The stack set the transaction to be terminated. The RA scans its transaction list for terminated transaction and found it before stack forwards 200 OK event to the RA. When that happened, the RA discards 200 OK event because the transaction is no longer existed.

What should happened is that stack should guarantee the 200 OK be forwarded before setting it to TERMINATED state.

I put the fix in the RA to delay the removal of the TERMINATED transaction for some seconds.

The run looks good now. I'll posted the new result later.

Francesco, it is appeared that using Call ID as a convergence name presents some memory leaks as well. When I change to ActivityContext then it seem to run fine

Leon Do

fram
Offline
Joined: 2004-05-13
Points: 0

Good catch I was struggling on the same bug ! The next version of the jain sip stack shoud have a listener that will inform the application for Transaction State changes.
I will double check the CallID convergence name to try to get rid of the memory leaks.
Francesco

ivelin
Offline
Joined: 2003-07-13
Points: 0

until the callbacks are implemented, should the RA have a simple state machine that removes a transaction after

it is invalid in the sip stack AND
(
(BYE was processed AND OK after that)
OR
(configurable number of seconds, e.g. 30, passed)
)
?

mranga
Offline
Joined: 2003-06-06
Points: 0

The callback that Francesco is referring to is the TransactionTerminated event that will be part of JAIN-SIP 1.2. (see discussion on that API in JAIN-SIP-INTEREST if you wish). What that will do is post an event to the JainSipListener (ie. the RA in our case) when the transaction is no longer mapped by the stack that is when it is removed. There will still be the possibility for this race condition to occur because of the Asynchronous processing model of the SLEE. What should be done is to return from the SIP Listener in the SIP RA on eventProcessingSuccessful. The other alternative is to put a little wait in like leon is suggesting.

The RA has no control over removing a SIP Transaction. So the solution suggested by Ivelin is not a valid one.

Ranga

ivelin
Offline
Joined: 2003-07-13
Points: 0

Thanks for the JAIN-SIP 1.2 pointer.

I am actually not suggesting that the RA removes the TX from the SIP stack. I am referring to the event that should make the RA *believe* that the tx is finished.

Ivelin

ivelin
Offline
Joined: 2003-07-13
Points: 0

Leon,

I thought that the cache is being configured to persiste state. Apparently I misunderstood.

Ivelin

profcalc
Offline
Joined: 2005-01-20
Points: 0

Hi

I tried doing some SIPp runs with today's fixes. (Leon is out).

Basically, the same behaviour as before i.e after a few messages, the run gets blocked as the SIPp UAC is waiting on a 200 OK response indefinitely (to a BYE), which as far as the log goes has been "sent" by the Proxy on the corresponding ClientTransaction.

One thing I observed is that the CacheMap which is caching the convergencenames for the Sbb entities for the service keeps increasing.
The code I'm referring to is

if (name != null) {
boolean found = false;
----> Set childSbbs = service.getConvergenceNames();
Iterator si = childSbbs.iterator();

inside of EventRouterImpl.java. (line 360 in my copy)

Basically, it seems for each event (request or response) being handled by the Service, there is a SBB entity created and cached ? Is this because I have the initial-event-select variable set to "ActivityContext" ? It wouldn't take long before this Map has really ballooned up.

I didn't notice the event sequencing issue that Leon noticed. Again, one thing to note is that the SLEE is not blocked, its just the SIPp client thread is blocked. So for example, I could start up another SIPP client on another port and send messages to the SLEE (i.e until that too gets blocked).

Well, there is definitely something strange going on. Will post if I find more.

Chetan
Lucent Technologies

mranga
Offline
Joined: 2003-06-06
Points: 0

I added a new Merge-able Map structure CachableMap that is apparently getting over zelous in the merging :-) so as to keep the cache in the "Read committed" level of consistency.

Yup something odd is going on. I will take a look when I can find some time.

Ranga

leondo
Offline
Joined: 2005-01-18
Points: 0

I have noticed SIP calls are being lost during the short performance run for a while and that prevented any further testing. After analyzing a few places and here is what I think what has happended:

The SBB attached to the ActivityContext at some point got removed from the AC after enter the transaction. Some data is losing in the transaction. When the SBB is not receiving the event then it will not processing the request. It almost happened right at the 200 OK response for BYE message. I captured the debug messages below that demostrated this and I added the comments along (see ####)

#####The SBB is attached to the ActivityContext######

2005-08-03 15:47:32,023 481865 DEBUG [org.mobicents.slee.runtime.ActivityContext] (7729940bcba5c985:704baa:1057ddb071a:-7f43,EventTypeID[javax.sip.message.Request.BYE#javax.sip#1.1], #14:) ActivityContext.printNode() {
activityContextId = 7729940bcba5c985:704baa:1057ddb071a:-7f41
sbbAttachmentSet = [7729940bcba5c985:704baa:1057ddb071a:-7f42]
getDeliveredSet() = []
namingBinding = []
attachedTimers = []
state = Active Activity Context
data = {}}

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.EventRouterImpl] (Thread-245:)

routeTheEvent : [[[javax.sip.ResponseEvent eventType EventTypeID[javax.sip.message.Response.SUCCESS#javax.sip#1.1], #28

#######Entered the transaction#################
2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.transaction.TransactionManagerImpl] (Thread-245:) Transaction started.

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.transaction.TransactionManagerImpl] (Thread-245:) Context local TxID: TransactionImpl:XidImpl [FormatId=257, GlobalId=leon//721, BranchQual=]

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.transaction.TransactionManagerImpl] (Thread-245:) Tx after begin:TransactionImpl:XidImpl [FormatId=257, GlobalId=leon//721, BranchQual=]

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.transaction.TransactionManagerImpl] (Thread-245:) Tx state is 0

########Get ActivityContext given the activity object#####
2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.ActivityContextFactoryImpl] (Thread-245:) getActivityContext(): for Object z9hG4bK5ccba8591dc2ab45f303332d99133145

######Found the ActivityContext ID############
2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.ActivityContextFactoryImpl] (Thread-245:) getActivityContext(): Getting AC ID 7729940bcba5c985:704baa:1057ddb071a:-7f41

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.ActivityContextFactoryImpl] (Thread-245:) getActivityContext(): MAP AC: activity -> acId {z9hG4bK67696c173532f2f66d7d0cf457089e87=7729940bcba5c985:704baa:1057ddb071a:-7f49, org.mobicents.slee.runtime.facilities.NullActivityImpl@1203875=7729940bcba5c985:704baa:1057ddb071a:-7fb6, org.mobicents.slee.runtime.facilities.NullActivityImpl@1125a40=7729940bcba5c985:704baa:1057ddb071a:-7fa4, org.mobicents.slee.runtime.facilities.NullActivityImpl@de3c87=7729940bcba5c985:704baa:1057ddb071a:-7fb1, z9hG4bK02356058a0cfa2363bc190b474c6BEE11=7729940bcba5c985:704baa:1057ddb071a:-7f43, z9hG4bK02356058a0cfa2363bc190b474c6BEE3=7729940bcba5c985:704baa:1057ddb071a:-7f83, z9hG4bK02356058a0cfa2363bc190b474c6BEE5=7729940bcba5c985:704baa:1057ddb071a:-7f73, z9hG4bK5ccba8591dc2ab45f303332d99133145=7729940bcba5c985:704baa:1057ddb071a:-7f41, z9hG4bK02356058a0cfa2363bc190b474c6BEE2=7729940bcba5c985:704baa:1057ddb071a:-7f8b, z9hG4bK02356058a0cfa2363bc190b474c6BEE7=7729940bcba5c985:704baa:1057ddb071a:-7f63, z9hG4bK02356058a0cfa2363bc190b474c6BEE1=7729940bcba5c985:704baa:1057ddb071a:-7f93, z9hG4bK02356058a0cfa2363bc190b474c6BEE8=7729940bcba5c985:704baa:1057ddb071a:-7f5b, org.mobicents.slee.runtime.facilities.NullActivityImpl@94cc7=7729940bcba5c985:704baa:1057ddb071a:-7fc1, org.mobicents.slee.runtime.serviceactivity.ServiceActivityImpl@1f150312=7729940bcba5c985:704baa:1057ddb071a:-7fc4, z9hG4bK02356058a0cfa2363bc190b474c6BEE9=7729940bcba5c985:704baa:1057ddb071a:-7f53, z9hG4bK02356058a0cfa2363bc190b474c6BEE4=7729940bcba5c985:704baa:1057ddb071a:-7f7b, org.mobicents.slee.runtime.facilities.NullActivityImpl@dec95c=7729940bcba5c985:704baa:1057ddb071a:-7f9c, z9hG4bK02356058a0cfa2363bc190b474c6BEE10=7729940bcba5c985:704baa:1057ddb071a:-7f4b, z9hG4bK02356058a0cfa2363bc190b474c6BEE6=7729940bcba5c985:704baa:1057ddb071a:-7f6b, org.mobicents.slee.runtime.facilities.NullActivityImpl@15651df=7729940bcba5c985:704baa:1057ddb071a:-7fa9}

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.ActivityContextFactoryImpl] (Thread-245:) getActivityContext(): MAP AC: acId-> AC {}

##########Didn't find the ActivityContext given the ActivityContext ID therefore create a new one. Why?????? #######

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.ActivityContext] (Thread-245:) ActivityContext.createActivityContext(): Creating activity context for z9hG4bK5ccba8591dc2ab45f303332d99133145

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.transaction.TransactionManagerImpl] (Thread-245:) Adding rollback action: org.mobicents.slee.runtime.ActivityContext$RollbackAction@1654

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.transaction.TransactionManagerImpl] (Thread-245:) TX is 28481438

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.transaction.TransactionManagerImpl] (Thread-245:) Adding prepare action: org.mobicents.slee.runtime.ActivityContext$PrepareAction@1b9e7df

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.transaction.TransactionManagerImpl] (Thread-245:) TX is 28481438

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.ActivityContext] (Thread-245:) ActivityContext.refreshActivityContext(): Loading activity context for z9hG4bK5ccba8591dc2ab45f303332d99133145

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.ActivityContext] (Thread-245:) ActivityContext.loadFromCache: activitycontext:7729940bcba5c985:704baa:1057ddb071a:-7f41

2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.ActivityContext] (Thread-245:) No cached image -- returning!

#######Now the SBB Entity is no longer attached to the AcitivityContext. This cause calls being lost########
2005-08-03 15:47:32,033 481875 DEBUG [org.mobicents.slee.runtime.ActivityContext] (Thread-245:) ActivityContext.printNode() {
activityContextId = 7729940bcba5c985:704baa:1057ddb071a:-7f41
sbbAttachmentSet = []
getDeliveredSet() = []
namingBinding = []
attachedTimers = []
state = Active Activity Context
data = {}}

Can someone take a look?
thanks
Leon Do

fram
Offline
Joined: 2004-05-13
Points: 0

I noticed that the proxy, during the message routing, is doing something really bad.
Every time the proxy routes a message is calling InetAddress.getLocalHost(), this can be a real performance killer.
For a quick fix you can modify the following method in com.opencloud.slee.services.sip.common.SipConfigImpl.java :
public String getSipHostname() {
String hostname = null;
/*try {
InetAddress addr = InetAddress.getLocalHost();

// Get IP Address
byte[] ipAddr = addr.getAddress();

// Get hostname
hostname = addr.getHostName();
return new String(hostname);
} catch (UnknownHostException e) {
}*/
// TODO Auto-generated method stub
return new String("129.6.50.114");
}
Where you should substitute the "129.6.50.114" address with the address of your machine.
I will change the code in order to initialize the SipConfigImpl once and then just get the intialized field of the class.
Francesco

leondo
Offline
Joined: 2005-01-18
Points: 0

>Ranga:1. Turn debug off. Redit log4j.xml to set the debug level to WARN or ERROR or something like that. DEBUG spews out a huge amount of debug. Grep for System.out.println in the code make them into logger.debug. These really slow things down. ( Indeed we have been rather careless - we should have these guarded by if ( logger.isDebugEnabled() ). As you notice such things please fix them up. )

Leon:I turned off the debug messages. You would be much better off by guarding them with the if though.

>Ranga:2. I am wondering what is going on here. An activity is mapped to a SIP transaction and there is one thread per activity in the multithreaded case so how is the response being processed before the request is sent out? It seems pretty odd to me.

Leon:Actually the response is a separate transaction. In the SIP scenario above, there are 6 transactions (2 for INVITE, 2 for ACK, 2 for BYE). Remember each forwarding is a separate transaction. Since you can have responses on the different transactions therefore you can run into synchronization issue. I used Activity Context as the selector method in the SBB xml.

>Ranga:3. Francesco noted that in the proxy we are looking up JNDI in sbbCreate. Really slows things down.

Leon:very true.

>Ranga:4. A couple of obvious performance enhancements are under way including loosening up the consistency model of the cache and getting rid of a number of places where we keep looking up JNDI for getting the Slee container. This should be happening just once.

Leon:Right

>Ranga:It would be good if you can also identify other possible ways in which performance can be improved. It is non trivial to get good performance out of this while following the required SERIALIZABLE consistency model mandated by the spec. We are working through some of these issues.

Leon:Beside things I have mentioned above. Some other things are:

-Can activity context id be cached locally instead of lookup in the tree cache everytime?
-The while loop in the EventRouter processInitialEvents to lookup the convergence name can be improved to do a hash lookup instead of looping. I saw the case where the SipResourceAdaptor didn't send the EventActitivyEnd which cause hundreds of SBB entities and convergence names remaining in the table and looping was nightmare.

>Ranga: A couple of performance improvements to some of the points you noted have already been made. Incidentally Sbb Entities are not re-used ever. They are not supposed to be. Perhaps you meant SbbObject? Yes theres a bunch of places where sbb objects are being re-created and dont need to be. For each such action, sbbCreate and postCreate is called and because the proxy does a lot of name lookup in these methods, there's a performance hit. These have been identified by Fran and we will hopefully fix these things up.

Leon:I was really meant SBB entities. The SIP Scenarios above required 3 SBB entities (INVITE, ACK, and BYE) because I have 3 incoming transactions. Now if you want to achieve anything less than 1 second per call then you cann't create 3 SBB entities per call. It looked to me that the creation of the SBB entities are very expensive. We need to find a way to reuse it (or reset it). Let me know if this possible.

>Ranga: At the end of the day this is only going to be as good as the effort we throw into it. Do you have a performance monitoring tool such as yourkit to help identify and nail down performance issues?

Leon:I used OptimizeIt but majority of time was looked at sipp results or peged some number within the container itself.

Ivelin, I wasn't sure what you meant by persistence. I didn't use tree cache with the persistance at all.

Leon Do

mranga
Offline
Joined: 2003-06-06
Points: 0

Leon,

In fact the sbb entities are cached in a per transaction cache. They cannot be cached globally ( breaks isolation). Reading from the treecache is unavoidable.

Can you try the version I just checked in. I made some important improvements - especially about hitting the service cache and using a looser (Read committed) consitency model for the cache.

I am sure you noticed Francesco's post in this thread. I think there are some important points there too.

You may want to only update src because I hacked the proxy a little for the failover front end.

Ranga

ivelin
Offline
Joined: 2003-07-13
Points: 0

Leon Do, another question is where exactly is JBoss Cache used with persistent storage? There should be very few cases where persistence is required.

Ivelin

ivelin
Offline
Joined: 2003-07-13
Points: 0

Updated the QA page to mention the SIPP examples and this forum thread.
http://wiki.java.net/bin/view/Communications/MobicentsQA

Ivelin

leondo
Offline
Joined: 2005-01-18
Points: 0

Hello,

This is my version of the run using single thread SLEE container build few weeks ago.

Hardware:
Solaris 9
4 CPUs :1.2 GH each
CPU usage: < 16%

INVITE scenarios

SIPP UAC PROXY SIPP UAS
INVITE ----------> -------------->
100 <----------
[ delay 10ms]
180 <---------- <---------------
[ delay 50ms]
200 <---------- <--------------
ACK ----------> --------------->
[ delay 500 ms]
BYE ----------> ---------------->
200 <---------- <---------------

total INVITEs sent: 2100 to 2363

Sip Driver: SIPP

SIP RA(ms/mesg) SLEE(ms/mesg) SIP PROXY(ms/mesg)
INVITE 1.42 344 265
180 .75 393 183
2x200 .73 641 187
ACK .78 434 4.5
BYE 1.6 431 279

Note: The SIP proxy has been configured to use the database and other things.

If one totals the time it took to process the INVITE scenario, then it takes about 3 seconds to process them and we are not close to 1c/s

- I did test Multi-thread container as well and the result did indicate some improvement but a very little. I cann't give the number because the some of the bugs in the container

Here is what my observations for the multi-thread container:
1. It looks like we spawn a new thread per event. There is no pooling.

2. Too many transaction operations which translate to many reading and writing to the tree cache. This looks like a very expensive perfomance penalty. The debug log showed a ton of below messages.

2005-07-25 15:10:37,792 592345 DEBUG [org.mobicents.slee.runtime.transaction.TransactionManagerImpl] (Thread-98:) getNode runtimeCache fqn = sbbentity:7729940bcba5c985:704baa:1054f5e51f8:-7fa4/activityContexts

3. For each SIP transaction, an SBB Entity is created and being destroyed. There is no reuseable whatsoever.

-Here is the synchronization issue:
While an SBB object is sending the request, its response has already arrived in the SLEE event router before the SBB object finished the method. This caused things to failed. Take a look at the code below in the SIP Proxy SBB.

protected ClientTransaction sendRequest(Request request,
boolean attach) throws SipException {
ClientTransaction ct =
provider.getNewClientTransaction(request);
ct.sendRequest();
if (attach) {
try {
ActivityContextInterface aci =
acif.getActivityContextInterface(ct);
aci.attach(getSbbLocalObject());
} catch (UnrecognizedActivityException e) {
trace(Level.WARNING, "unable to attach to client
transaction", e);
}
}
return ct;
}

In my case, the response to the ct.sendRequest() arrive before the SBB attach is ready.

Let me know if you are having any comments
Leon Do

mranga
Offline
Joined: 2003-06-06
Points: 0

First, this is a good test. Good work! I am not amazed (or dismayed) by the poor performance. Much tuning lies ahead and we are working on it .

A few quick points :

1. Turn debug off. edit log4j.xml to set the debug level to WARN or ERROR or something like that. DEBUG spews out a huge amount of debug. Grep for System.out.println in the code make them into logger.debug. These really slow things down. ( Indeed we have been rather careless - we should have these guarded by if ( logger.isDebugEnabled() ). As you notice such things please fix them up. )

2. I am wondering what is going on here. An activity is mapped to a SIP transaction and there is one thread per activity in the multithreaded case so how is the response being processed before the request is sent out? It seems pretty odd to me.

3. Francesco noted that in the proxy we are looking up JNDI in sbbCreate. Really slows things down.

4. A couple of obvious performance enhancements are under way including loosening up the consistency model of the cache and getting rid of a number of places where we keep looking up JNDI for getting the Slee container. This should be happening just once.

It would be good if you can also identify other possible ways in which performance can be improved. It is non trivial to get good performance out of this while following the required SERIALIZABLE consistency model mandated by the spec. We are working through some of these issues.

A couple of performance improvements to some of the points you noted have already been made. Incidentally Sbb Entities are not re-used ever. They are not supposed to be. Perhaps you meant SbbObject? Yes theres a bunch of places where sbb objects are being re-created and dont need to be. For each such action, sbbCreate and postCreate is called and because the proxy does a lot of name lookup in these methods, there's a performance hit. These have been identified by Fran and we will hopefully fix these things up.

At the end of the day this is only going to be as good as the effort we throw into it. Do you have a performance monitoring tool such as yourkit to help identify and nail down performance issues?

Finally, yes one thread per activity is what we have now. We need to add a thread factory to set the thread limit to the number of processors.

Ranga