[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.

To illustrate where the delays are occurring during shutdown, I
installed the following log function to version 4.0.3 on HP-UX 11:

#include <time.h>
static void logTime (const char *s)
{
    char            buf[17];
    static double   total, offset = 0;
    struct timespec ts;
    if (clock_gettime (CLOCK_REALTIME, &ts) != -1)
        {
        total = (double) ts.tv_sec  +
                (double) ts.tv_nsec * 1.e-9;
        if (offset == 0)
            offset = total;
        else
            total -= offset;
        sprintf (buf, "%.2f ", total);
        fputs (buf, stderr);
        }
    fputs (s, stderr);
}
...
omniORB::setLogFunction (logTime);
omniORB::traceLevel = 40;
theOrb->shutdown (1);
...

It prepends the delta time from start of ORB shutdown to the log
messages.  Below are excerpts of the messages for various values
of ORBscanGranularity.  It shows a delay after the message

   giopServer waits for completion of rendezvousers and workers

as well as after the message

   AsyncInvoker: thread id = 1 has exited. Total threads = 3

(when present).

ORBscanGranularity = 60
=======================
0.00 omniORB: (0) Stopping serving incoming endpoints.
0.00 omniORB: (0) giopServer waits for completion of rendezvousers and workers
10.10 omniORB: (1) AsyncInvoker: thread id = 1 has exited. Total threads = 3
36.85 omniORB: (2) Scan for idle connections (1074031992,671698000)
36.85 omniORB: (2) Scavenger reduce idle count for strand 400cbcc0 to 1
36.85 omniORB: (2) Scavenger reduce idle count for strand 40427000 to 2
36.85 omniORB: (2) Scan for idle connections done (1074031992,671698000).
56.01 omniORB: (3) throw giopStream::CommFailure from giopStream.cc:828(0,NO,COMM_FAILURE_UnMarshalArguments)
56.01 omniORB: (3) Server connection refcount = 1

ORBscanGranularity = 30
=======================
0.00 omniORB: (0) Stopping serving incoming endpoints.
0.00 omniORB: (0) giopServer waits for completion of rendezvousers and workers
9.46 omniORB: (2) Scan for idle connections (1074032203,304669000)
9.46 omniORB: (2) Scavenger reduce idle count for strand 400cbcc0 to 3
9.46 omniORB: (2) Scavenger reduce idle count for strand 40427000 to 5
9.47 omniORB: (2) Scan for idle connections done (1074032203,304669000).
10.10 omniORB: (1) AsyncInvoker: thread id = 1 has exited. Total threads = 3
25.52 omniORB: (3) throw giopStream::CommFailure from giopStream.cc:828(0,NO,COMM_FAILURE_UnMarshalArguments)
25.53 omniORB: (3) Server connection refcount = 1

ORBscanGranularity = 10
=======================
0.00 omniORB: (0) Stopping serving incoming endpoints.
0.01 omniORB: (0) giopServer waits for completion of rendezvousers and workers
4.62 omniORB: (3) throw giopStream::CommFailure from giopStream.cc:828(0,NO,COMM_FAILURE_UnMarshalArguments)
4.62 omniORB: (3) Server connection refcount = 1

ORBscanGranularity = 2
======================
0.00 omniORB: (0) Stopping serving incoming endpoints.
0.00 omniORB: (0) giopServer waits for completion of rendezvousers and workers
0.48 omniORB: (3) throw giopStream::CommFailure from giopStream.cc:828(0,NO,COMM_FAILURE_UnMarshalArguments)
0.49 omniORB: (3) Server connection refcount = 1