[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