[omniORB] ORBscanGranularity == shutdown time?

[Roloff, Craig A]

On Monday 15 December, Grisby, Duncan" wrote:
> On Thursday 11 December, "Roloff, Craig A" wrote:
> 
> > Why is there a relationship between ORBscanGranularity (SG) and the
> > shutdown time?  It appears when shutdown (1) is executed that it
> > takes somewhat less than SG seconds to complete.  Here is a table
> > of SG vs shutdown times (in seconds) for a particular applicaton:
> 
> Shutdown time shouldn't be affected by the scan granularity at all.
> 
> What version of omniORB are you using?  Please try with 4.0.3. If you
> still get the delays, please run the traces again with
> -ORBtraceThreadId 1.

At least part of the problem occurs in the Scavenger::execute()
method.  It sets a condition timed wait == scanGranularity.  As
near as I can tell, the only way to exit the condition before it
times out is via the Scavenger::terminate() method.  But that
doesn't get invoked until *after* the ORB shutdown is complete,
at least according to the trace logs shown below.

Note - I inserted the following traces into the execute method:

omni_thread::get_time(&abs_sec,&abs_nsec,orbParameters::scanGranularity);
omniORB::logs(25, "Scavenger setting timed wait");
cond->timedwait(abs_sec,abs_nsec);
omniORB::logs(25, "Scavenger finished timed wait");

as well as the following in the terminate method:

shutdown = 1;
omniORB::logs(25, "Scavenger signaling timed wait");
cond->signal();

ORBscanGranularity = 60
=======================
...
0.00 omniORB: (0) Stopping serving incoming endpoints.
0.01 omniORB: (0) giopServer waits for completion of rendezvousers and workers
10.11 omniORB: (1) AsyncInvoker: thread id = 1 has exited. Total threads = 3
31.90 omniORB: (2) Scavenger finished timed wait
31.90 omniORB: (2) Scan for idle connections (1074790827,511564000)
31.90 omniORB: (2) Scavenger reduce idle count for strand 400cc4e0 to 1
31.90 omniORB: (2) Scavenger reduce idle count for strand 40427000 to 2
31.90 omniORB: (2) Scan for idle connections done (1074790827,511564000).
31.90 omniORB: (2) Scavenger setting timed wait
53.73 omniORB: (3) throw giopStream::CommFailure from giopStream.cc:828(0,NO,COMM_FAILURE_UnMarshalArguments)
...

ORBscanGranularity = 30
=======================
...
0.00 omniORB: (0) Stopping serving incoming endpoints.
0.00 omniORB: (0) giopServer waits for completion of rendezvousers and workers
10.09 omniORB: (1) AsyncInvoker: thread id = 1 has exited. Total threads = 3
15.47 omniORB: (2) Scavenger finished timed wait
15.47 omniORB: (2) Scan for idle connections (1074791165,403780000)
15.47 omniORB: (2) Scavenger reduce idle count for strand 400cc4e0 to 3
15.47 omniORB: (2) Scavenger reduce idle count for strand 40427000 to 5
15.47 omniORB: (2) Scan for idle connections done (1074791165,403780000).
15.47 omniORB: (2) Scavenger setting timed wait
25.21 omniORB: (3) throw giopStream::CommFailure from giopStream.cc:828(0,NO,COMM_FAILURE_UnMarshalArguments)
...

ORBscanGranularity = 10
=======================
...
0.01 omniORB: (0) giopServer waits for completion of rendezvousers and workers
4.60 omniORB: (3) throw giopStream::CommFailure from giopStream.cc:828(0,NO,COMM_FAILURE_UnMarshalArguments)
...

ORBscanGranularity = 2
=======================
...
0.00 omniORB: (0) giopServer waits for completion of rendezvousers and workers
0.84 omniORB: (3) throw giopStream::CommFailure from giopStream.cc:828(0,NO,COMM_FAILURE_UnMarshalArguments)
...