Discussion:
[omniORB] Optimizing the roundtrip-time of function calls?
Oliver Frick
2009-04-26 02:19:55 UTC
Permalink
How can I optimize a function call's roundtrip time?
I have measured the up-call and return time of a corba
call between two processes on the same host.
The result is always that the up-call time is much smaller
than the return time. The ratio is typically 1/5,
sometimes 1/100 or more.
The function is rather simple, it has no arguments
(or two longs; I added them for testing) and always two
longs in a returned struct.

If the ORB is able to up-call the other object in, say
150 usec, why does it need 1.5 msec to return? Can I
reduce the return time by configuring omniorb?

Oliver Frick
Duncan Grisby
2009-04-28 19:55:05 UTC
Permalink
Post by Oliver Frick
How can I optimize a function call's roundtrip time?
I have measured the up-call and return time of a corba
call between two processes on the same host.
The result is always that the up-call time is much smaller
than the return time. The ratio is typically 1/5,
sometimes 1/100 or more.
The function is rather simple, it has no arguments
(or two longs; I added them for testing) and always two
longs in a returned struct.
If the ORB is able to up-call the other object in, say
150 usec, why does it need 1.5 msec to return? Can I
reduce the return time by configuring omniorb?
How are you measuring it? I would not expect that, and have never seen
anything to suggest that return handling was slower than incoming call
handling.

How are you configuring omniORB? Are you using bidirectional GIOP?

Cheers,

Duncan.
--
-- Duncan Grisby --
-- ***@grisby.org --
-- http://www.grisby.org --
Oliver Frick
2009-04-29 00:08:00 UTC
Permalink
Hello Duncan.
Post by Duncan Grisby
Post by Oliver Frick
How can I optimize a function call's roundtrip time?
I have measured the up-call and return time of a corba
call between two processes on the same host.
The result is always that the up-call time is much smaller
than the return time. The ratio is typically 1/5,
sometimes 1/100 or more.
The function is rather simple, it has no arguments
(or two longs; I added them for testing) and always two
longs in a returned struct.
If the ORB is able to up-call the other object in, say
150 usec, why does it need 1.5 msec to return? Can I
reduce the return time by configuring omniorb?
How are you measuring it? I would not expect that, and have never seen
anything to suggest that return handling was slower than incoming call
handling.
I take time-stamps from the hires system clock immediately before and
after the call on the client side and during the call on the server
side.
(hires_clock() is a wrapper to platform specific high resolution clocks,
e.g. PerformanceCounter under Windows).

client:
hires_clock_t a = hires_clock();
obj->Foo();
hires_clock_t b = hires_clock();

server:
void Server:: Foo()
{
hires_clock_t m = hires_clock();
}

Since it is the same clock (both processes run on the same host)
the time-stamps are compatible:
(m - a) = (b - m) / R
with R between 4 and 10, sometimes higher.

I get similar results on Windows XP and Mac OS 10.5.
Post by Duncan Grisby
How are you configuring omniORB? Are you using bidirectional GIOP?
I've tested both. Activating in a bidir POA and in the root POA:
same result. I have also variated the oneCallPerConnection parameter.

Here is the config output on Mac OS 10.5.6:

omniORB: Version: 4.1.3
omniORB: Distribution date: Tue Sep 23 10:43:28 BST 2008 dgrisby
omniORB: My addresses are:
omniORB: 127.0.0.1
omniORB: ::1
omniORB: <my LAN ip>
omniORB: <my WAN ip>
omniORB: Maximum supported GIOP version is 1.2
omniORB: Native char code sets: UTF-8 ISO-8859-1.
omniORB: Transmission char code sets: UTF-8(1.2) UTF-8(1.1)
ISO-8859-1(1.2) ISO-8859-1(1.1) ISO-8859-1(1.0).
omniORB: Native wide char code sets: UTF-16.
omniORB: Transmission wide char code sets: UTF-16(1.2).
omniORB: Initialising omniDynamic library.
omniORB: Current configuration is as follows:
omniORB: DefaultInitRef (file) =
omniORB: DefaultInitRef (args) =
omniORB: abortOnInternalError = 0
omniORB: abortOnNativeException = 0
omniORB: acceptBiDirectionalGIOP = 1
omniORB: acceptMisalignedTcIndirections = 0
omniORB: bootstrapAgentHostname =
omniORB: bootstrapAgentPort = 900
omniORB: clientCallTimeOutPeriod = 0
omniORB: clientConnectTimeOutPeriod = 0
omniORB: clientTransportRule = * unix,tcp,ssl,bidir
omniORB: configFile = <path deleted>
omniORB: connectionWatchImmediate = 0
omniORB: connectionWatchPeriod = 50000
omniORB: copyValuesInLocalCalls = 1
omniORB: diiThrowsSysExceptions = 0
omniORB: dumpConfiguration = 0
omniORB: endPoint = giop:tcp::2809
omniORB: endPointPublish = addr
omniORB: giopMaxMsgSize = 2097152
omniORB: giopTargetAddressMode = KeyAddr
omniORB: id = omniORB4
omniORB: idleThreadTimeout = 10
omniORB: immediateAddressSwitch = 0
omniORB: inConScanPeriod = 180
omniORB: lcdMode = 0
omniORB: maxGIOPConnectionPerServer = 5
omniORB: maxGIOPVersion = 1.2
omniORB: maxInterleavedCallsPerConnection = 5
omniORB: maxServerThreadPerConnection = 100
omniORB: maxServerThreadPoolSize = 100
omniORB: maxSocketRecv = 2147483647
omniORB: maxSocketSend = 2147483647
omniORB: nativeCharCodeSet = ISO-8859-1
omniORB: nativeWCharCodeSet = UTF-16
omniORB: objectTableSize = 0
omniORB: offerBiDirectionalGIOP = 0
omniORB: oneCallPerConnection = 0
omniORB: outConScanPeriod = 120
omniORB: poaHoldRequestTimeout = 0
omniORB: poaUniquePersistentSystemIds = 1
omniORB: principal = [Null]
omniORB: resetTimeOutOnRetries = 0
omniORB: scanGranularity = 5
omniORB: serverCallTimeOutPeriod = 0
omniORB: serverTransportRule = * unix,tcp,ssl,bidir
omniORB: socketSendBuffer = -1
omniORB: strictIIOP = 1
omniORB: supportBootstrapAgent = 0
omniORB: supportCurrent = 1
omniORB: supportPerThreadTimeOut = 0
omniORB: tcAliasExpand = 0
omniORB: threadPerConnectionLowerLimit = 9000
omniORB: threadPerConnectionPolicy = 1
omniORB: threadPerConnectionUpperLimit = 10000
omniORB: threadPoolWatchConnection = 1
omniORB: traceExceptions = 1
omniORB: traceFile = [stderr]
omniORB: traceInvocationReturns = 0
omniORB: traceInvocations = 1
omniORB: traceLevel = 25
omniORB: traceThreadId = 0
omniORB: traceTime = 0
omniORB: unixTransportDirectory = /tmp/omni-%u
omniORB: unixTransportPermission = 777
omniORB: useTypeCodeIndirections = 1
omniORB: validateUTF8 = 0
omniORB: verifyObjectExistsAndType = 1
Duncan Grisby
2009-04-30 22:04:01 UTC
Permalink
Post by Oliver Frick
I take time-stamps from the hires system clock immediately before and
after the call on the client side and during the call on the server
side.
[...]
Post by Oliver Frick
Since it is the same clock (both processes run on the same host)
(m - a) = (b - m) / R
with R between 4 and 10, sometimes higher.
I get similar results on Windows XP and Mac OS 10.5.
Are you able to post your complete test code? I've tried an experiment
with Linux, and it doesn't show any significant variation between the
times.

One possible explanation is that the exact way your test works causes an
interaction with the OS scheduler. When the client makes the call, it
sends the request then immediately blocks on the connection waiting for
the reply. The OS will therefore immediately go looking for a process to
run next, and will find that the server can wake up. On the other hand,
after the server sends its reply it has various housekeeping to do, so
it doesn't block immediately. There is therefore more scope for delay
before the OS notices that the client is runnable again.

Cheers,

Duncan.
--
-- Duncan Grisby --
-- ***@grisby.org --
-- http://www.grisby.org --
Loading...