From: koren@fc.hp.com (Steve Koren)
Subject: Unusual SAS6.0 results
Date: Sun, 15 Nov 1992 19:48:07 GMT
Organization: Hewlett-Packard Fort Collins Site
X-Newsreader: Tin 1.1.3 PL5

Ok, I'm clueless.

I upgraded from SAS 5.1b to 6.0, and recompiled some source with the
new version, and am getting some interesting results, some of them
a bit distrubing.

1. I have a binary which I compiled under 5.10b and OS2.04.  It had
no enforcer hits when run under OS2.04.  If I moved that same binary
over to 3.0, it got a lot of enforcer hits.  If I recompiled the
source under SAS6.0 and OS3.0, the very same source generates a binary
which is back to getting no enforcer hits.  This is good, I guess,
but I don't understand it.

2. GENPROTO mode crashes the machine a lot.  I get consistant crashes
on 2 out of 30 source files.  No big deal though; I can generate the
prototypes by hand.

3. This is the real thing I'm worried about.  I have about 22000 lines
of source which is divided into 39 small executables and one medium
sized executable.  The conversion process from 5.10b to 6.0 was relatively
painless; 6.0 is a bit more strict about type checking, but other than
than, it all compiled with no errors or warnings.  All the small
executables (2-8K, a few hundred lines max) work just great under 6.0,
and in fact are smaller than they were before.  They appear to run
with the same speed.  However, the medium sized executable is not
so happy.  It runs as before, but it is *much* slower.  I'm talking
about 20X here.  It is getting no enforcer hits; I've checked that.  Since
I really wanted to get it back to its old execution speed, I did a
lprof and lstat on it.  I'm getting _really_ wierd results.  Here is
the 1st few lines from the lstat output:

 95.4023%  95.4023%   f97c      249 _strncpy  <- I DON'T CALL THIS!
  0.7662%  96.1685%   7c58        2 @Read_String [lines 290-327 in Lexer.c]
  0.7662%  96.9349%   92d4        2 _yyparse [lines 966-1103 in Parser.y.C]

I'm apparently spending 95% of my time in strncpy, which is really wierd
because I don't actually _call_ strncpy anywhere in my source.  I searched
every single source file and nothing calls strncpy.  I do call strcpy, but
not very much.  I ran the debug executable through cpr, put a breakpoint
on strncpy, and executed, and I never hit it.  I don't even understand why
it is being linked into my code (but it is, I checked that).

The profile results when I compile this source under 2.04 with SAS5.10b
look "normal".  There is a more or less even distribution of time spent in
the routines I expect.  But under 6.0, all my time is spent in this mystical
strncpy which I don't even think I'm calling.

What's going on?  Interestingly enough, the strncpy is taking ~95% of the
execution time, and my program is running about 95% slower than it was
before.  Dunno if that's a coincidence or not.  I do need to get it back
to its 5.10b execution speed though.

BTW, the program which is running 20X slower basically does this: some
FGets() calls, a bit of processing to build a parse tree out of that
data, and an execution of that parse tree.  The rough times I see are:

  Old 5.10b executable: 1 second
  New 6.0 execeutable:  15 to 20 seconds

  - steve "confused" k