In debugging XCF-2985(XECS-1854), I noticed that there was a really long
delay in the sipXsupervisor log between when the XML/RPC request was
received (from Config) and when it was actually printed out (up to 2
minutes in some cases). This in turn caused sipXConfig to timeout
waiting for a response on the success or failure of the replication.
Note: sipXsupervisor currently doesn't have a config parameter for
setting the debug level and it is
defaulted right now to DEBUG. This explains why the XML/RPC
request is being logged.
Further investigation showed that the OsSysLog facility seemed to be the
one causing this enormous delay and of course blocking sipXsupervisor
for most of that time until it passes on the complete message to another
task for actual logging.
The logging facility seems to have a couple of methods
(OsSysLog::escape, OsSysLog::myvsprintf) which are allocating/resizing
UtlString(s) a high number of times in a lot of cases. The constant
resizing of the UtlString(s) is what is causing the large delays.
I'd like to propose modifying the identified methods (escape and
myvsprintf) to be a little smarter in how its allocating the
UtlString(s) to avoid the resizing as much as possible. This will not
only resolve the replication issue but will probably make the logging a
lot more efficient.
OsSysLog::escape
- accepts a UtlString as source and returns an escaped version of the
source in another UtlString.
- I'd like to modify the result (return) string so that its
size/capacity is set to be at least the size of the source UltString.
This will drastically reduce the amount of resizing that needs to occur.
------------------------------------------------------------------------
-----------------------------
-Question: Would it be best to actually set the initial capacity to the
size of the source + some additional buffering since the escaped version
will actually be a longer. If so, then how much extra buffering should
I put?
------------------------------------------------------------------------
-----------------------------
OsSysLog::myvsprintf
- A version of vsprintf that stores the result in a UtlString.
- This method starts by allocating a UtlString of 900 bytes and tries to
copy the initial string into it (after parm substitution). If it fails
because the string is too small, it doubles the size and tries again.
This continues until its successful.
- I'd like to modify the allocation of the UtlString to be at least the
"sizeof" of the format character string passed in if its greater than
900 bytes. This will reduce the amount of resizing that needs to occur
for strings longer than 900 bytes.
------------------------------------------------------------------------
----------------------------
-Question: Would it be best to actually set the initial capacity to the
"sizeof" of the format character string + some additional buffering
since the resulting UtlString will probably be longer. If so, then how
much extra buffering should I put?
------------------------------------------------------------------------
----------------------------
I have made these changes and tested the replication that was failing
before.
My system had 2100 users defined and the delay in processing (becausing
of the logging) was 2 minutes. With my changes in place, the entire
sipXsupervisor replication (from reading, logging, replicating and
returning the result) was about 2 to 3 seconds. The size of the XML/RPC
request was approximately 1.5 Mb.
I then pumped up the number of users to 3200 and the processing was now
about 4 seconds. Certainly much better than before.
Raymond
_______________________________________________
sipx-dev mailing list
[email protected]
List Archive: http://list.sipfoundry.org/archive/sipx-dev
Unsubscribe: http://list.sipfoundry.org/mailman/listinfo/sipx-dev
