On 1995-09-01 09:55, Jonathan de Boyne Pollard of 2:440/4 wrote:

Hi, I finally got around to trying out your suggestion...

PE>
 >                                                 This program
 > when profiled registers 95% of the time spent in DosSubSet!!!
 >
 > #include 
 >
 > static char buf[30000];
 >
 > int main(void)
 > {
 >     int x;
 >     FILE *fq;
 >
 >     fq = fopen("temp.txt", "wb");
 >     for (x = 0; x < 2000; x++)
 >     {
 >         fwrite(buf, sizeof buf, 1, fq);
 >     }
 >     fclose(fq);
 >     return (0);
 > }
PE>

JdBP>   Stop and think.  Your profiler cannot register time spent in a device
JdBP>   or filesystem driver, nor does it register time spent blocked waiting
JdBP>   for I/O requests to complete in the bottom half of the kernel.

It can if it does it the way CSET does it - ie, a decent profiler.

JdBP>   Therefore the 95% figure for DosSubSet is a percentage of the time
JdBP>   spent outside of I/O, not for the total execution time of your
JdBP>   application.

Perhaps.  If so, it should be showing up under the "unknown"
instead of the "doscall.lib".  I would be happier about it telling
me that it doesn't know where the time is being spent rather than
telling me that it's being spent in dossubset.

JdBP>   Considering that your program does little else *other* than I/O, what
JdBP>   you are actually measuring is the profiling information for the C++
JdBP>   runtime startup and cleanup code and the buffering in the 
JdBP>   library.  The library initialisation and terminating code does little
JdBP>   else than allocate buffers (for things like `stdin' and the argument
JdBP>   list) so it's unsurprising that profiling it reveals that most of its
JdBP>   time is spent in memory management routines.  The same goes for the
JdBP>    library.

JdBP>   To "unskew" your profiling measurements, try putting
some non-I/O code
JdBP>   in the body of your program (generate a series of 1000 random numbers
JdBP>   in every iteration of the loop, or something) and then profiling it.

Ok, I modified the program as below...

#include 

#include 

static char buf[30000];

int main(void)
{
    int x;
    HFILE fq;
    APIRET rc;
    ULONG  action;
    ULONG  newsize = 0;
    ULONG  fileAttr = 0;
    ULONG  openAction = 0;
    ULONG  openMode = 0;
    size_t towrite;
    ULONG actualWritten;
    int y, z = 5;
    
    openAction |= OPEN_ACTION_CREATE_IF_NEW;
    openAction |= OPEN_ACTION_REPLACE_IF_EXISTS;
    openMode |= OPEN_ACCESS_WRITEONLY;
    openMode |= OPEN_SHARE_DENYWRITE;
    rc = DosOpen("temp.txt",
                 &fq,
                 &action, 
                 newsize, 
                 fileAttr,
                 openAction, 
                 openMode, 
                 NULL);
    towrite = sizeof buf;
    for (x = 0; x < 2000; x++)
    {
        for (y = 0; y < 20000; y++)
        {
            z = z * 3;
            if (z == 2)
            {
                printf("fooled you you stupid optimizer!\n");
            }
        }
        rc = DosWrite(fq, buf, towrite, &actualWritten);
    }
    DosClose(fq);
    return (0);
}

And then I did the tests again.  Let me summarize:

The first program is obviously near-100% I/O (DosWrite).  The Watcom
profiler says that 99.7% of the time is being spent in DosSubSet.
The elapsed time for running the first program is 37.8 seconds.  So
I/O is 37.8 seconds.  

Now the second program takes 64 seconds to run, which means 37.8
seconds I/O and 26 seconds for that silly loop.  In other words, 
a 60:40 split approximately.

Now, according to your theory, if that time spent in DosSubset was
showing startup overhead, then we should now see DosSubset 
registering somewhat less than 0.1% of the total execution time.
However, the Watcom profiler says:

DosSubset - 23%
profile (main program) - 76.6%.

So your theory is not correct.  But what theory is correct?  The
only logical things for Watcom to tell me are either:

profile (main program) - 100%

or 

profile (main program) - 40%
something else - 60%

Since it does neither, all I can say is that I don't trust Watcom's
profiler as far as I can throw it, and will stick to using CSET
for my profiling work.  Very very shoddy this profiler from Watcom.
Mark Kimes's C compiler produced the proper results too.  Even better
than CSET, because CSET will only go down to the function level, and
not tell you which line of code it was that had all the time spent
in it, which is important in the case of the program above.  CSET 2.0
is what I'm using.  BFN.  Paul.
@EOT:

---