Discussion:
[omniORB] time taken by destry()
sheena kansal
2013-09-25 08:46:47 UTC
Permalink
Hi,

We are calling a obj->destroy() to clear all the objects and seeing more
time taken by AsyncInvoker: deleted.

what could be the reason for this? below are traces from level 10---

$ omniORB: (?) 2013-09-24 20:13:44.740600: Initial reference
`NameService_LOCAL'
resolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.742032: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.745391: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0
omniORB: (?) 2013-09-24 20:13:44.747413: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.748861: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.754000: Creating ref to remote: root/Fips
ST PO
A<5175657279536572/1986618213>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:SVPD/QueryService:1.0
omniORB: (?) 2013-09-24 20:13:44.757467: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.761327: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.763322: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0
omniORB: (?) 2013-09-24 20:13:44.769426: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.770733: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.772683: Creating ref to remote: root/Fips
ST PO
A<5175657279536572/1986618213>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:SVPD/QueryService:1.0
omniORB: (?) 2013-09-24 20:13:44.779531: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.780836: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.786015: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0

omniORB: (?) 2013-09-24 20:13:44.787756: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.791943: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.793904: Creating ref to remote: root/Fips
ST PO
A<5175657279536572/1986618213>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:SVPD/QueryService:1.0
smgrinit: omniORB: (15) 2013-09-24 20:13:44.829809: AsyncInvoker: thread id
= 15
has started. Total threads = 4
smgrinit: omniORB: (15) 2013-09-24 20:13:44.830754: Accepted connection
from gio
p:unix:/tmp/forb.socket.fsp.a.smgrinit 00000019 because of this rule: "*
unix,tc
p"
omniORB: (?) 2013-09-24 20:13:44.842697: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.847074: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.849616: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0
omniORB: (?) 2013-09-24 20:13:44.857886: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.859208: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.861298: Creating ref to remote: root/Fips
ST PO
A<5175657279536572/1986618213>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:SVPD/QueryService:1.0
omniORB: (?) 2013-09-24 20:13:44.873654: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.874991: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.878700: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0
omniORB: (?) 2013-09-24 20:13:44.880484: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.884895: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.890067: Creating ref to remote: root/Fips
ST PO
A<5175657279536572/1986618213>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:SVPD/QueryService:1.0
omniORB: (?) 2013-09-24 20:13:44.899771: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.901108: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.903281: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0
omniORB: (?) 2013-09-24 20:13:44.905220: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.906564: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.908561: Creating ref to remote: root/Fips
MT PO
A<dbServ.obj>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:dbServer:1.0
omniORB: (?) 2013-09-24 20:13:44.930251: Preparing to shutdown ORB.
omniORB: (?) 2013-09-24 20:13:44.930882: Shutting-down all incoming
endpoints.
omniORB: (?) 2013-09-24 20:13:44.931581: ORB shutdown is complete.
omniORB: (?) 2013-09-24 20:13:49.934572: AsyncInvoker: deleted.
omniORB: (?) 2013-09-24 20:13:49.962742: Final clean-up completed.
smgrinit: omniORB: (15) 2013-09-24 20:13:54.933696: AsyncInvoker: thread id
= 15
has exited. Total threads = 4
--
Regards,
Sheena
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.omniorb-support.com/pipermail/omniorb-list/attachments/20130925/7112368e/attachment.html>
sheena kansal
2013-09-25 11:34:35 UTC
Permalink
Tried again, after changing scanGranularity from 5sec to 1 sec

1 sec
------

omniORB: (0) 2003-03-26 07:17:10.952285: Wait for 1 invoker thread to
finish.
omniORB: (1) 2003-03-26 07:17:10.952360: AsyncInvoker: thread id = 1 has
exited. Total threads = 1
omniORB: (0) 2003-03-26 07:17:10.952767: Invoker threads finished.
omniORB: (0) 2003-03-26 07:17:10.952836: AsyncInvoker: deleted.

5 sec
-------
omniORB: (?) 2003-03-26 07:37:19.143838: Wait for 1 invoker thread to
finish.
omniORB: (?) 2003-03-26 07:37:19.110588: omniRemoteIdentity deleted.
omniORB: (?) 2003-03-26 07:37:19.110692: ObjRef(IDL:DataView:1.0) --
deleted.
omniORB: (?) 2003-03-26 07:37:19.205954: omniRemoteIdentity deleted.
omniORB: (?) 2003-03-26 07:37:19.206052: ObjRef() -- deleted.
omniORB: (?) 2003-03-26 07:37:19.206472: ORB not destroyed; no final
clean-up.
omniORB: (?) 2003-03-26 07:37:24.143913: Timed out. 1 invoker threads
remaining.
omniORB: (?) 2003-03-26 07:37:24.144533: AsyncInvoker: deleted.

with 1 sec it is able to delete the threads, but not after timeout of 5
sec. Why is it so? isn;t it should be able to delete the thread with
scanGranularity 5 also?

Regards.
Sheena
---------- Forwarded message ----------
From: sheena kansal <sheena.kansal at gmail.com>
Date: Wed, Sep 25, 2013 at 2:16 PM
Subject: time taken by destry()
To: omniorb-list at omniorb-support.com


Hi,

We are calling a obj->destroy() to clear all the objects and seeing more
time taken by AsyncInvoker: deleted.

what could be the reason for this? below are traces from level 10---

$ omniORB: (?) 2013-09-24 20:13:44.740600: Initial reference
`NameService_LOCAL'
resolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.742032: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.745391: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0
omniORB: (?) 2013-09-24 20:13:44.747413: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.748861: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.754000: Creating ref to remote: root/Fips
ST PO
A<5175657279536572/1986618213>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:SVPD/QueryService:1.0
omniORB: (?) 2013-09-24 20:13:44.757467: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.761327: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.763322: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0
omniORB: (?) 2013-09-24 20:13:44.769426: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.770733: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.772683: Creating ref to remote: root/Fips
ST PO
A<5175657279536572/1986618213>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:SVPD/QueryService:1.0
omniORB: (?) 2013-09-24 20:13:44.779531: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.780836: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.786015: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0

omniORB: (?) 2013-09-24 20:13:44.787756: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.791943: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.793904: Creating ref to remote: root/Fips
ST PO
A<5175657279536572/1986618213>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:SVPD/QueryService:1.0
smgrinit: omniORB: (15) 2013-09-24 20:13:44.829809: AsyncInvoker: thread id
= 15
has started. Total threads = 4
smgrinit: omniORB: (15) 2013-09-24 20:13:44.830754: Accepted connection
from gio
p:unix:/tmp/forb.socket.fsp.a.smgrinit 00000019 because of this rule: "*
unix,tc
p"
omniORB: (?) 2013-09-24 20:13:44.842697: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.847074: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.849616: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0
omniORB: (?) 2013-09-24 20:13:44.857886: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.859208: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.861298: Creating ref to remote: root/Fips
ST PO
A<5175657279536572/1986618213>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:SVPD/QueryService:1.0
omniORB: (?) 2013-09-24 20:13:44.873654: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.874991: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.878700: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0
omniORB: (?) 2013-09-24 20:13:44.880484: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.884895: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.890067: Creating ref to remote: root/Fips
ST PO
A<5175657279536572/1986618213>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:SVPD/QueryService:1.0
omniORB: (?) 2013-09-24 20:13:44.899771: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.901108: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.903281: Creating ref to remote: root/Fips
MT PO
A<ServerReady>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:ServerReady:1.0
omniORB: (?) 2013-09-24 20:13:44.905220: Initial reference
`NameService_LOCAL' r
esolved from configuration file.
omniORB: (?) 2013-09-24 20:13:44.906564: Creating ref to remote:
key<NameService
target id : IDL:omg.org/CosNaming/NamingContext:1.0
most derived id:
omniORB: (?) 2013-09-24 20:13:44.908561: Creating ref to remote: root/Fips
MT PO
A<dbServ.obj>
target id : IDL:omg.org/CORBA/Object:1.0
most derived id: IDL:dbServer:1.0
omniORB: (?) 2013-09-24 20:13:44.930251: Preparing to shutdown ORB.
omniORB: (?) 2013-09-24 20:13:44.930882: Shutting-down all incoming
endpoints.
omniORB: (?) 2013-09-24 20:13:44.931581: ORB shutdown is complete.
omniORB: (?) 2013-09-24 20:13:49.934572: AsyncInvoker: deleted.
omniORB: (?) 2013-09-24 20:13:49.962742: Final clean-up completed.
smgrinit: omniORB: (15) 2013-09-24 20:13:54.933696: AsyncInvoker: thread id
= 15
has exited. Total threads = 4
--
Regards,
Sheena
--
Regards,
Sheena
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.omniorb-support.com/pipermail/omniorb-list/attachments/20130925/3a7dabab/attachment.html>
Duncan Grisby
2013-09-26 08:13:41 UTC
Permalink
Post by sheena kansal
We are calling a obj->destroy() to clear all the objects and seeing
more time taken by AsyncInvoker: deleted.
I assume you mean orb->destroy()...
Post by sheena kansal
what could be the reason for this? below are traces from level 10---
That doesn't show enough detail. Please run with traceLevel 25.

Duncan.
--
-- Duncan Grisby --
-- duncan at grisby.org --
-- http://www.grisby.org --
sheena kansal
2013-09-30 18:07:52 UTC
Permalink
below are traces from level 25 -

Tried again, after changing scanGranularity from 5sec to 1 sec,

1 sec
------

omniORB: (0) 2003-03-26 07:17:10.952285: Wait for 1 invoker thread to
finish.
omniORB: (1) 2003-03-26 07:17:10.952360: AsyncInvoker: thread id = 1 has
exited. Total threads = 1
omniORB: (0) 2003-03-26 07:17:10.952767: Invoker threads finished.
omniORB: (0) 2003-03-26 07:17:10.952836: AsyncInvoker: deleted. ------> all
threads deleted and destroyed immediately

5 sec
-------
omniORB: (?) 2003-03-26 07:37:19.143838: Wait for 1 invoker thread to
finish.
omniORB: (?) 2003-03-26 07:37:19.110588: omniRemoteIdentity deleted.
omniORB: (?) 2003-03-26 07:37:19.110692: ObjRef(IDL:DataView:1.0) --
deleted.
omniORB: (?) 2003-03-26 07:37:19.205954: omniRemoteIdentity deleted.
omniORB: (?) 2003-03-26 07:37:19.206052: ObjRef() -- deleted.
omniORB: (?) 2003-03-26 07:37:19.206472: ORB not destroyed; no final
clean-up.
omniORB: (?) 2003-03-26 07:37:24.143913: Timed out. 1 invoker threads
remaining. ----> there is a timeout after 5 sec
omniORB: (?) 2003-03-26 07:37:24.144533: AsyncInvoker: deleted.

with 1 sec it is able to delete the threads, but not if timeout is 5 sec.
Why is it so? isn;t it should be able to delete the thread with
scanGranularity of 5 also?

Regards.
Sheena
Post by Duncan Grisby
Post by sheena kansal
We are calling a obj->destroy() to clear all the objects and seeing
more time taken by AsyncInvoker: deleted.
I assume you mean orb->destroy()...
Post by sheena kansal
what could be the reason for this? below are traces from level 10---
That doesn't show enough detail. Please run with traceLevel 25.
Duncan.
--
-- Duncan Grisby --
-- duncan at grisby.org --
-- http://www.grisby.org --
--
Regards,
Sheena
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.omniorb-support.com/pipermail/omniorb-list/attachments/20130930/c979e4ab/attachment.html>
Duncan Grisby
2013-10-10 08:12:55 UTC
Permalink
Post by sheena kansal
below are traces from level 25 -
I need the whole traces. In particular, I need to see the startup
messages and see what thread id 1 was doing, and what happened when
ORB::destroy() was called.

[...]
Post by sheena kansal
omniORB: (?) 2003-03-26 07:37:19.206472: ORB not destroyed; no final
clean-up.
omniORB is of the opinion that you didn't call destroy() on the ORB.

Duncan.
--
-- Duncan Grisby --
-- duncan at grisby.org --
-- http://www.grisby.org --
Loading...