It was easier to document than I thought...
1) Decide what program(s) to 'profile':
You would probably only profile the header program FIRST, then see
what called subroutines are taking a while in total, then switch your
profiling to THAT subroutine only. The profiler generates A LOT of data, so
you don't want to profile all 35,000,000 lines of code you've written in a
single sitting!
2) Compile the programs you want to target with a -G option
BASIC BP PROGTOTEST -G
3) Run the program using the -G option.
RUN BP PROGTOTEST -G
Note: If your PROGTOTEST is an embedded subroutine, no problem, you
would type RUN BP MASTERPROG -G , and the -G option would start profiling on
the MASTERPROG in 'summary', but would do 'detail' profiling on the program
PROGTOTEST as you compiled it with the -G option.
4) Shell to the account you are working in and find files marked
'profile.NNN' and 'profile.elapse.NNN', where NNN = PID. These are NT or
*nix files - not VOC entries. So you can't see them until you go to to OS
level for the account you are in.
The profile.NNN shows the time in actual CPU usage...
It shows
%time of time spent in the listed routine, cumulative time in secs(*more on
this in a moment), seconds spent on this routine, calls to this routine,
routine name
The profile.elapse.NNN shows the time on the CLOCK, so if you had to key
data in to a subroutine, you can expect to see it near the top of the % of
time occupied.
%time spent in the listed routine, cumulative seconds spent to date on the
funtions (*more on this in a moment), Raw Seconds spent, # calls to this
routine, routine name.
The Cumulative time is not sequential: You may see data like this:
%time CumSec Seconds Calls Name
10.0 3.00 3.00 1 d:\account\_ROUTINEC
10.0 6.00 3.00 1 d:\account\_ROUTINEA
6.7 8.00 2.00 1 d:\account\_ROUTINEB
See - the CumSecs is not the time elapsed for the ORDER the routines
processed in, but the Cumulative time for the routines in the order of %time
spent.
Also - if you have not compiled a routine with a -G option, the WHOLE
ROUTINE shows up on one line, as shown above. However, if you had keyed
ROUTINEC with a -G option, you would see this instead:
%time CumSec Seconds Calls Name
10.0 3.00 3.00 1 d:\account\_ROUTINEA
6.7 5.00 2.00 1 d:\account\_ROUTINEB
5.0 6.50 1.50 6 d:\account\_ROUTINEC:1000
2.5 7.25 .75 1 d:\account\_ROUTINEC:10
2.5 8.00 .75 1 d:\account\_ROUTINEC:100
Where the # after the colon is the internal subroutine label being
exectuted. In this case, I can see subroutine 1000 is called 6 times in the
program, so that works out to be .25 seconds a use. Not much to fix there
compared to 10 and 100 at .75 each, UNLESS I didn't know subroutine 1000 was
being called 6 times!
As I said, you can find out SO much about your code running this - you may
realize that optimizing one or two sections of a program will have a large
impact. As well, once you get a printout of what programs are using what
amount of time, it will lead you to do a -G on them - in the example above,
I can see I should also profile ROUTINEA to see if I can hammer out some
time from the routine.
Once you are done with profiling, you should recompile the program WITHOUT
the -G option - this will produce the smaller object code again since it
will be built without the 'profile' handles.
Hope that helps someone!
David Wolverton
-----Original Message-----
From: [EMAIL PROTECTED] [mailto:[EMAIL PROTECTED] On
Behalf Of David Wolverton
Sent: Friday, March 19, 2004 12:30 PM
To: 'U2 Users Discussion List'
Subject: RE: Unidata "Flashbasic"
I'll do it before the weekend is over... It's *very* cool, and useful too -
what a great combo! <g>
DW
-----Original Message-----
From: [EMAIL PROTECTED] [mailto:[EMAIL PROTECTED] On
Behalf Of Wendy Smoak
Sent: Friday, March 19, 2004 10:49 AM
To: U2 Users Discussion List
Subject: RE: Unidata "Flashbasic"
David Wolverton wrote:
> if you
> compile a routine with UniData's Profiler Option 'on', the really
> interesting thing is that you can see where the system is spending a
> lot of time, or doing a lot of recursion - you can see clock time
> spent, CPU time spent, and number of times the subroutine was called.
Would you be willing to post a HOWTO? Where do you set this option, what
does the output look like? This sounds very interesting but is yet another
thing that would take me half a day to figure out.
If you sketch out the basics I'll fill in the details and put it on the
Wiki.
--
Wendy Smoak
Application Systems Analyst, Sr.
ASU IA Information Resources Management
--
u2-users mailing list
[EMAIL PROTECTED]
http://www.oliver.com/mailman/listinfo/u2-users
--
u2-users mailing list
[EMAIL PROTECTED]
http://www.oliver.com/mailman/listinfo/u2-users
--
u2-users mailing list
[EMAIL PROTECTED]
http://www.oliver.com/mailman/listinfo/u2-users
