[omniORB] Memory leak on orb shutdown due to giopServer 'Closed 0
connections out of 1.'
Martin B.
0xCDCDCDCD at gmx.at
Wed Jan 5 15:02:54 GMT 2011
Hi all, Hi Duncan!
[omniORB 4.1.2] (But note that a diff of the 4.1.2 sources vs. the
newest 4.1.5 sources did not show any differences in the code I have
problems with.)
I currently face a bit a confusing state with my test client and I would
like to get some input on this.
My problem is that the giopServer singleton is not deleted, (apparently)
due to a timeout when shutting down the ORB.
This is extremely annoying, as we rely on the MS CRT mechanism to detect
memory leaks, and therefore need to make sure any app never ever leaks
anything.
It only happens 50% of the runs (and with logging 25 enabled, I need to
restart my testclient about 10 times for one timeout to happen).
(All connections are locally on a Windows XP sp3 box)
Here's a sketch of what happens in the code:
1.1) ORB is initialized and some object references are obtained from the
server
1.2) Some local callback objects for the server are created
1.3) My main thread calls orb->run();
1.4) A second thread does some calls on the serevr and then terminates.
...
2) Shutdown is initiated via a CORBA call that invokes orb->shutdown(false);
3) omniOrbORB::do_shutdown launches the shutdown thread
4) omniOrbORB::actual_shutdown() calls omniOrbPOA::shutdown()
4.1) This call stack eventually leads to giopServer::deactivate()
4.2) which then times out on pd_cond on line 646 "Wait for
<pd_n_dedicated_workers> dedicated thread to finish..."
4.3) which sets the timed_out variable to true
4.4) which sets pd_state = TIMEDOUT;
5) Then, in the next step omniObjAdapter::shutdown(); is called by
actual_shutdown()
5.1) which calls giopServer::remove()
5.2) which hits pd_state==TIMEDOUT
5.3) which prevents delete this;
6) Eventually shutdown finishes, run() returns and orb->destroy() is called.
7) The process terminates normally without any problems (apart from the
leaked giopServer object).
The timeout time in 4.2 depends on "scanGranularity" as far as I can see
and the only timing settingg I found that may influence the timing out
of socket connections is ORBconnectionWatchPeriod which seems to be the
timeout used for the select call of the connection thread that times
out. (But this is set to a default of only 50ms.)
Find logging below.
any help appreciated,
cheers,
Martin
Here's the logging (level 25):
(see lines marked with ***)
(note that scanGranularity = 3 here, but it also happens if left on 5)
- - - - - -
omniORB: 2011-01-05 14:08:48.015000: Version: 4.1.2
omniORB: 2011-01-05 14:08:48.015000: Distribution date: Thu Feb 14
14:19:08 GMT 2008 dgrisby
omniORB: 2011-01-05 14:08:48.187000: Warning: unable to create an IPv6
socket. Unable to obtain the list of IPv6 interface addresses (10047).
omniORB: 2011-01-05 14:08:48.187000: My addresses are:
omniORB: 192.168.102.1
omniORB: 192.168.154.1
omniORB: 172.27.169.2
omniORB: 127.0.0.1
omniORB: 2011-01-05 14:08:48.187000: Maximum supported GIOP version is 1.2
omniORB: 2011-01-05 14:08:48.187000: Native char code sets: UTF-8
ISO-8859-1.
omniORB: 2011-01-05 14:08:48.187000: 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: 2011-01-05 14:08:48.187000: Native wide char code sets: UTF-16.
omniORB: 2011-01-05 14:08:48.187000: Transmission wide char code sets:
UTF-16(1.2).
omniORB: 2011-01-05 14:08:48.187000: Initialising omniDynamic library.
omniORB: 2011-01-05 14:08:48.187000: Current configuration is as follows:
omniORB: DefaultInitRef (file) =
omniORB: DefaultInitRef (args) =
omniORB: InitRef = NameService=corbaname::trappelm.ksengineers.at
omniORB: abortOnInternalError = 0
omniORB: abortOnNativeException = 0
omniORB: acceptBiDirectionalGIOP = 0
omniORB: acceptMisalignedTcIndirections = 0
omniORB: bootstrapAgentHostname =
omniORB: bootstrapAgentPort = 900
omniORB: clientCallTimeOutPeriod = 0
omniORB: clientConnectTimeOutPeriod = 0
omniORB: clientTransportRule = * unix,ssl,tcp
omniORB: configFile = [none]
omniORB: connectionWatchImmediate = 0
omniORB: connectionWatchPeriod = 50000
omniORB: copyValuesInLocalCalls = 1
omniORB: diiThrowsSysExceptions = 0
omniORB: dumpConfiguration = 0
omniORB: endPoint = giop:tcp::
omniORB: endPointPublish = giop:tcp:trappelm.ksengineers.at:
omniORB: giopMaxMsgSize = 10485760
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 = 131072
omniORB: maxSocketSend = 131072
omniORB: nativeCharCodeSet = ISO-8859-1
omniORB: nativeWCharCodeSet = UTF-16
omniORB: objectTableSize = 0
omniORB: offerBiDirectionalGIOP = 0
omniORB: oneCallPerConnection = 1
omniORB: outConScanPeriod = 120
omniORB: poaHoldRequestTimeout = 0
omniORB: poaUniquePersistentSystemIds = 1
omniORB: principal = [Null]
omniORB: resetTimeOutOnRetries = 0
omniORB: scanGranularity = 3
omniORB: serverCallTimeOutPeriod = 0
omniORB: serverTransportRule = * unix,ssl,tcp
omniORB: socketSendBuffer = 16384
omniORB: strictIIOP = 1
omniORB: supportBootstrapAgent = 1
omniORB: supportCurrent = 1
omniORB: supportPerThreadTimeOut = 0
omniORB: tcAliasExpand = 0
omniORB: threadPerConnectionLowerLimit = 9000
omniORB: threadPerConnectionPolicy = 1
omniORB: threadPerConnectionUpperLimit = 10000
omniORB: threadPoolWatchConnection = 1
omniORB: traceExceptions = 0
omniORB: traceFile = C:\temp\omniORB.log
omniORB: traceInvocationReturns = 0
omniORB: traceInvocations = 0
omniORB: traceLevel = 25
omniORB: traceThreadId = 0
omniORB: traceTime = 1
omniORB: unixTransportDirectory = /tmp/omni-%u
omniORB: unixTransportPermission = 777
omniORB: useTypeCodeIndirections = 1
omniORB: verifyObjectExistsAndType = 1
omniORB: 2011-01-05 14:08:48.187000: Initialising incoming endpoints.
...
...
omniORB: 2011-01-05 14:09:16.906000: Preparing to shutdown ORB.
omniORB: 2011-01-05 14:09:16.906000: Starting an ORB shutdown thread.
omniORB: 2011-01-05 14:09:16.906000: ORB shutdown thread started.
omniORB: 2011-01-05 14:09:16.906000: Destroying POA(RootPOA).
omniORB: 2011-01-05 14:09:16.906000: Deactivating all POA(RootPOA)'s
objects.
omniORB: 2011-01-05 14:09:16.906000: State root<0> (active) ->
deactivating (OA destruction)
omniORB: 2011-01-05 14:09:16.906000: Waiting for requests to complete on
POA(RootPOA).
omniORB: 2011-01-05 14:09:16.906000: Requests on POA(RootPOA) completed.
omniORB: 2011-01-05 14:09:16.906000: State root<0> (deactivating OA) ->
etherealising
omniORB: 2011-01-05 14:09:16.906000: Etherealising POA(RootPOA)'s objects.
omniORB: 2011-01-05 14:09:16.906000: Removing root<0> (etherealising)
from object table
omniORB: 2011-01-05 14:09:16.906000: ServantBase has zero ref count --
deleted.
omniORB: 2011-01-05 14:09:16.906000: Wait for 0 detached objects.
omniORB: 2011-01-05 14:09:16.906000: All object adapters inactive.
Stopping serving incoming endpoints.
omniORB: 2011-01-05 14:09:16.906000: giopServer deactivate...
omniORB: 2011-01-05 14:09:16.906000: Close connections with threads and
monitors...
omniORB: 2011-01-05 14:09:16.906000: sendCloseConnection: to
giop:tcp:172.27.169.2:2879 12 bytes
omniORB: 2011-01-05 14:09:16.906000: Closed 1 connection out of 1.
***
omniORB: 2011-01-05 14:09:16.906000: Wait for 1 dedicated thread to
finish...
omniORB: 2011-01-05 14:09:19.906000: Timed out. 1 connection and 1
dedicated worker remaining.
***
omniORB: 2011-01-05 14:10:16.921000: Terminate rendezvousers...
omniORB: 2011-01-05 14:10:16.921000: giopRendezvouser for
giop:tcp:192.168.102.1:2877 terminate...
omniORB: 2011-01-05 14:10:16.921000: Server connection refcount = 1
omniORB: 2011-01-05 14:12:21.453000: giopRendezvouser for endpoint
giop:tcp:192.168.102.1:2877 exit.
omniORB: 2011-01-05 14:12:21.453000: No remaining rendezvousers.
omniORB: 2011-01-05 14:12:37.921000: Rendezvousers terminated.
omniORB: 2011-01-05 14:12:37.921000: Close remaining connections...
***
omniORB: 2011-01-05 14:12:37.921000: Closed 0 connections out of 1.
***
omniORB: 2011-01-05 14:12:37.921000: giopServer deactivated.
omniORB: 2011-01-05 14:12:37.921000: Destruction of POA(RootPOA) complete.
omniORB: 2011-01-05 14:12:37.921000: Shutting-down all incoming endpoints.
omniORB: 2011-01-05 14:14:38.203000: AsyncInvoker: thread id = 1 has
exited. Total threads = 3
omniORB: 2011-01-05 14:14:38.203000: TCP endpoint shut down.
omniORB: 2011-01-05 14:14:38.203000: Disable ObjRef()
key<TornadoDatamanager>
omniORB: 2011-01-05 14:14:38.203000: omniRemoteIdentity deleted.
omniORB: 2011-01-05 14:14:38.203000: Server connection refcount = 0
omniORB: 2011-01-05 14:14:38.203000: Server close connection from
giop:tcp:172.27.169.2:2879
omniORB: 2011-01-05 14:14:38.203000: Disable
ObjRef(IDL:kse/tornado/datamanager/IDatamanagerClient:1.0) root<0>
omniORB: 2011-01-05 14:14:38.203000: Object table entry root<0> (dead)
deleted.
omniORB: 2011-01-05 14:14:38.203000: 2 object references present at ORB
shutdown.
omniORB: 2011-01-05 14:14:38.203000: ORB shutdown is complete.
omniORB: 2011-01-05 14:14:38.203000: Deinitialising omniDynamic library.
omniORB: 2011-01-05 14:14:38.203000: Release registered value factories.
omniORB: 2011-01-05 14:14:38.203000: Terminate strand scavenger.
omniORB: 2011-01-05 14:14:38.203000: Close remaining strands.
omniORB: 2011-01-05 14:14:38.203000: Shutdown close connection to
giop:tcp:trappelm.ksengineers.at:5995
omniORB: 2011-01-05 14:14:38.203000: sendCloseConnection: to
giop:tcp:172.27.169.2:5995 12 bytes
omniORB: 2011-01-05 14:14:38.203000: Client connection refcount (forced) = 0
omniORB: 2011-01-05 14:14:38.203000: Client close connection to
giop:tcp:172.27.169.2:5995
omniORB: 2011-01-05 14:14:38.203000: Shutdown close connection to
giop:tcp:localhost:5995
omniORB: 2011-01-05 14:14:38.203000: Client connection refcount (forced) = 0
omniORB: 2011-01-05 14:14:38.203000: Client close connection to
giop:tcp:127.0.0.1:5995
omniORB: 2011-01-05 14:14:38.203000: 0 remaining bidir ropes deleted.
omniORB: 2011-01-05 14:14:38.203000: 2 remaining ropes deleted.
omniORB: 2011-01-05 14:14:38.203000: Clear endPoint options.
omniORB: 2011-01-05 14:14:38.203000: Wait for 2 invoker threads to finish.
omniORB: 2011-01-05 14:14:38.203000: AsyncInvoker: thread id = 4 has
exited. Total threads = 2
omniORB: 2011-01-05 14:14:38.203000: AsyncInvoker: thread id = 3 has
exited. Total threads = 2
omniORB: 2011-01-05 14:14:38.203000: Invoker threads finished.
omniORB: 2011-01-05 14:14:38.203000: AsyncInvoker: deleted.
omniORB: 2011-01-05 14:14:39.031000: ObjRef() -- deleted.
omniORB: 2011-01-05 14:14:39.031000:
ObjRef(IDL:kse/tornado/datamanager/IDatamanagerClient:1.0) -- deleted.
omniORB: 2011-01-05 14:14:39.031000: No more references to the ORB --
deleted.
omniORB: 2011-01-05 14:14:39.031000: Released 2 stub TypeCodes from
'boxesDynSK.cc'.
omniORB: 2011-01-05 14:14:39.031000: Unregister value factory for
'IDL:omg.org/CORBA/WStringValue:1.0'.
omniORB: 2011-01-05 14:14:39.031000: Unregister value factory for
'IDL:omg.org/CORBA/StringValue:1.0'.
omniORB: 2011-01-05 14:14:39.031000: Released 21 stub TypeCodes from
'NamingDynSK.cc'.
omniORB: 2011-01-05 14:14:39.031000: Released 75 stub TypeCodes from
'irDynSK.cc'.
omniORB: 2011-01-05 14:14:39.031000: Released 46 stub TypeCodes from
'corbaidlDynSK.cc'.
omniORB: 2011-01-05 14:14:39.031000: Released 4 stub TypeCodes from
'bootstrapDynSK.cc'.
omniORB: 2011-01-05 14:14:39.031000: Released 7 stub TypeCodes from
'poa_enumsDynSK.cc'.
omniORB: 2011-01-05 14:14:39.031000: Released 1 stub TypeCode from
'unknownUserExn.cc'.
omniORB: 2011-01-05 14:14:39.031000: Released 2 stub TypeCodes from
'policy.cc'.
omniORB: 2011-01-05 14:14:39.046000: Released 60 stub TypeCodes from
'dynException.cc'.
omniORB: 2011-01-05 14:14:39.046000: Final clean-up
omniORB: 2011-01-05 14:14:39.046000: Release value factory table.
omniORB: 2011-01-05 14:14:39.046000: Released 21 stub TypeCodes from
'typecode.cc'.
omniORB: 2011-01-05 14:14:39.046000: Deleted 8 nil object references and
4 other tracked objects.
omniORB: 2011-01-05 14:14:39.046000: Final clean-up completed.
- - - - - -
More information about the omniORB-list
mailing list