diff: changes for .profcalls grades
Fergus Henderson
fjh at hydra.cs.mu.oz.au
Mon Nov 17 23:57:24 AEDT 1997
Fix some problems with the `.profcalls' grade (`--profile-calls' option).
profiler/process_file.m:
If the `Prof.Counts' file does not exist, print a warning message
and then continue, rather than calling error/1. This is needed
so that the `.profcalls' grade (or `--profile-calls' option) will
work. (Thanks to Dominique de Waleffe <ddw at miscrit.be> for reporting
this bug.)
profiler/generate_output.m:
Use "number of calls" as a secondary key, after "percent time",
when creating the flat profile. This gives more useful results
for cases where timing information is not available (e.g. in
the `.profcalls' grade).
profiler/generate_output.m:
profiler/output.m:
Use `*', `+' etc. functions rather than builtin_float_times, etc.
cvs diff: Diffing .
Index: generate_output.m
===================================================================
RCS file: /home/staff/zs/imp/mercury/profiler/generate_output.m,v
retrieving revision 1.16
diff -u -u -r1.16 generate_output.m
--- generate_output.m 1997/07/28 08:59:32 1.16
+++ generate_output.m 1997/11/17 11:17:43
@@ -45,10 +45,16 @@
% output_prof structure.
rbtree(float, string), % associate call graph
% percentage with a name.
- rbtree(float, string) % as above except for flat
+ rbtree(flat_key, string) % as above except for flat
% profile.
).
+:- type flat_key --->
+ flat_key(
+ float, % per cent time in this predicate
+ int % number of calls to this predicate
+ ).
+
generate_output__main(Prof, IndexMap, Output) -->
% Get intitial values of use.
@@ -149,14 +155,14 @@
(
HertzFloat = 0.0
->
- Selftime = 0.0,
+ SelfTime = 0.0,
DescTime = 0.0
;
- Selftime is InitialFloat / HertzFloat * ClockTicksFloat,
+ SelfTime is InitialFloat / HertzFloat * ClockTicksFloat,
DescTime is (InitialFloat+Prop) / HertzFloat * ClockTicksFloat
),
- OutputProfNode = output_cycle_prof( Name, CycleNum, Selftime,
+ OutputProfNode = output_cycle_prof( Name, CycleNum, SelfTime,
DescPercentage,
DescTime, TotalCalls, SelfCalls,
[], []
@@ -221,15 +227,15 @@
(
HertzFloat = 0.0
->
- Selftime = 0.0,
+ SelfTime = 0.0,
DescTime = 0.0
;
- Selftime is InitialFloat / HertzFloat * ClockTicksFloat,
+ SelfTime is InitialFloat / HertzFloat * ClockTicksFloat,
DescTime is (InitialFloat+Prop) / HertzFloat
* ClockTicksFloat
),
- process_prof_node_parents(ParentList, Selftime, DescTime,
+ process_prof_node_parents(ParentList, SelfTime, DescTime,
TotalCalls, CycleNum, CycleMap,
OutputParentList, OutputCycleParentList),
process_prof_node_children(ChildList, CycleNum, CycleMap,
@@ -237,7 +243,7 @@
OutputProfNode = output_prof( Name, CycleNum,
DescPercentage,
- FlatPercentage, Selftime,
+ FlatPercentage, SelfTime,
DescTime, TotalCalls,
SelfCalls,
OutputParentList,
@@ -249,8 +255,9 @@
map__det_insert(InfoMap0, LabelName, OutputProfNode, InfoMap),
rbtree__insert_duplicate(CallTree0, DescPercentage,
LabelName, CallTree),
- rbtree__insert_duplicate(FlatTree0, FlatPercentage,
- LabelName, FlatTree),
+ rbtree__insert_duplicate(FlatTree0, flat_key(FlatPercentage,
+ TotalCalls),
+ LabelName, FlatTree),
OutputProf = profiling(InfoMap, CallTree, FlatTree)
).
@@ -276,12 +283,12 @@
cycle_map, list(parent), list(parent)).
:- mode process_prof_node_parents(in, in, in, in, in, in, out, out) is det.
-process_prof_node_parents(Parents0, Selftime, DescTime, TotalCalls0, CycleNum,
+process_prof_node_parents(Parents0, SelfTime, DescTime, TotalCalls0, CycleNum,
CycleMap, OutputParentList, OutputCycleParentList) :-
remove_cycle_members(Parents0, TotalCalls0, CycleNum, CycleMap,
TotalCalls, Parents, OutputCycleParentList),
int__to_float(TotalCalls, FltTotalCalls),
- process_prof_node_parents_2(Parents, Selftime, DescTime, FltTotalCalls,
+ process_prof_node_parents_2(Parents, SelfTime, DescTime, FltTotalCalls,
CycleMap, OutputParentList).
@@ -330,10 +337,10 @@
:- mode process_prof_node_parents_2(in, in, in, in, in, out) is det.
process_prof_node_parents_2([], _, _, _, _, []).
-process_prof_node_parents_2([P | Ps], Selftime, DescTime, TotalCalls,
+process_prof_node_parents_2([P | Ps], SelfTime, DescTime, TotalCalls,
CycleMap, OutputParentList) :-
rbtree__init(Output0),
- process_prof_node_parents_3([P | Ps], Selftime, DescTime,
+ process_prof_node_parents_3([P | Ps], SelfTime, DescTime,
TotalCalls, CycleMap,
Output0, Output),
rbtree__values(Output, OutputParentList).
@@ -344,7 +351,7 @@
:- mode process_prof_node_parents_3(in, in, in, in, in, in, out) is det.
process_prof_node_parents_3([], _, _, _, _, Output, Output).
-process_prof_node_parents_3([PN | PNs], Selftime, DescTime, TotalCalls,
+process_prof_node_parents_3([PN | PNs], SelfTime, DescTime, TotalCalls,
CycleMap, Output0, Output) :-
pred_info_get_entire(PN, LabelName, Calls),
@@ -364,14 +371,14 @@
% due to the parent.
% and the amount of the current predicate's descendant-time spent
% due to the parent.
- builtin_float_times(Selftime, Proportion, PropSelftime),
- builtin_float_times(DescTime, Proportion, PropDescTime),
+ PropSelfTime is SelfTime * Proportion,
+ PropDescTime is DescTime * Proportion,
- Parent = parent(LabelName, ParentCycleNum, PropSelftime,
+ Parent = parent(LabelName, ParentCycleNum, PropSelfTime,
PropDescTime, Calls),
rbtree__insert_duplicate(Output0, Calls, Parent, Output1),
- process_prof_node_parents_3(PNs, Selftime, DescTime, TotalCalls,
+ process_prof_node_parents_3(PNs, SelfTime, DescTime, TotalCalls,
CycleMap, Output1, Output).
@@ -450,7 +457,7 @@
prof_node_get_total_calls(ProfNode, TotalCalls),
int__to_float(Initial, InitialFloat),
- builtin_float_plus(InitialFloat, Prop, CurrentCount),
+ CurrentCount is InitialFloat + Prop,
int__to_float(TotalCalls, FloatTotalCalls),
int__to_float(Calls, FloatCalls),
@@ -459,22 +466,20 @@
% Calculate the self time spent in the current predicate.
int__to_float(Hertz, HertzFloat),
int__to_float(ClockTicks, ClockTicksFloat),
- checked_float_divide(InitialFloat, HertzFloat, InterA),
- builtin_float_times(InterA, ClockTicksFloat, Selftime),
+ SelfTime is (InitialFloat / HertzFloat) * ClockTicksFloat,
% Calculate the descendant time, which is the time spent in the
% current predicate and its descendants
- builtin_float_divide(CurrentCount, HertzFloat, InterB),
- builtin_float_times(InterB, ClockTicksFloat, DescTime),
+ DescTime is (CurrentCount / HertzFloat) * ClockTicksFloat,
% Calculate the amount of the current predicate's self-time spent
% due to the parent.
% and the amount of the current predicate's descendant-time spent
% due to the parent.
- builtin_float_times(Selftime, Proportion, PropSelftime),
- builtin_float_times(DescTime, Proportion, PropDescTime),
+ PropSelfTime is SelfTime * Proportion,
+ PropDescTime is DescTime * Proportion,
- Child = child(LabelName, CycleNum, PropSelftime, PropDescTime, Calls,
+ Child = child(LabelName, CycleNum, PropSelfTime, PropDescTime, Calls,
TotalCalls),
rbtree__insert_duplicate(Output0, Calls, Child, Output1),
process_prof_node_children_2(PNs, Prof, Output1, Output).
@@ -511,15 +516,14 @@
profiling_init(Profiling) :-
map__init(InfoMap),
- rbtree__init(EmptyTree),
- CallTree = EmptyTree,
- FlatTree = EmptyTree,
+ rbtree__init(CallTree),
+ rbtree__init(FlatTree),
Profiling = profiling(InfoMap, CallTree, FlatTree).
checked_float_divide(A, B, C) :-
( B = 0.0 ->
C = 0.0
;
- builtin_float_divide(A, B, C)
+ C is A / B
).
Index: output.m
===================================================================
RCS file: /home/staff/zs/imp/mercury/profiler/output.m,v
retrieving revision 1.15
diff -u -u -r1.15 output.m
--- output.m 1997/07/27 15:07:49 1.15
+++ output.m 1997/11/17 06:04:25
@@ -371,13 +371,11 @@
FloatTotalCalls is FloatTotalCalls0 + FloatSelfCalls,
Calls is SelfCalls + TotalCalls,
-
-
- builtin_float_plus(Self, CumTime0, CumTime),
- checked_float_divide(Self, FloatTotalCalls, Self1),
- checked_float_divide(Descendant, FloatTotalCalls, Desc1),
- builtin_float_times(1000.0, Self1, SelfMs),
- builtin_float_times(1000.0, Desc1, DescMs),
+ CumTime is CumTime0 + Self,
+ checked_float_divide(Self, FloatTotalCalls, SelfSeconds),
+ checked_float_divide(Descendant, FloatTotalCalls, DescSeconds),
+ SelfMs is 1000.0 * SelfSeconds,
+ DescMs is 1000.0 * DescSeconds,
output__construct_name(Name, CycleNum, FullName),
string__int_to_string(Index, IndexStr0),
Index: process_file.m
===================================================================
RCS file: /home/staff/zs/imp/mercury/profiler/process_file.m,v
retrieving revision 1.15
diff -u -u -r1.15 process_file.m
--- process_file.m 1997/07/27 15:07:50 1.15
+++ process_file.m 1997/11/17 05:59:14
@@ -47,23 +47,26 @@
% globals__io_lookup_string_option(libraryfile, LibFile),
globals__io_lookup_bool_option(dynamic_cg, Dynamic),
+ % process the decl file
maybe_write_string(VVerbose, "\n\t% Processing "),
maybe_write_string(VVerbose, DeclFile),
maybe_write_string(VVerbose, "..."),
-
process_addr_decl(AddrDeclMap, ProfNodeMap0),
+ maybe_write_string(VVerbose, " done.\n"),
- maybe_write_string(VVerbose, " done.\n\t% Processing "),
+ % process the timing counts file
+ maybe_write_string(VVerbose, "\t% Processing "),
maybe_write_string(VVerbose, CountFile),
maybe_write_string(VVerbose, "..."),
- process_addr(ProfNodeMap0, ProfNodeMap1, Hertz, ClockTicks,TotalCounts),
+ process_addr(ProfNodeMap0, ProfNodeMap1, Hertz, ClockTicks,
+ TotalCounts),
+ maybe_write_string(VVerbose, " done.\n"),
- maybe_write_string(VVerbose, " done.\n\t% Processing "),
+ % process the call pair counts file
+ maybe_write_string(VVerbose, "\t% Processing "),
maybe_write_string(VVerbose, PairFile),
maybe_write_string(VVerbose, "..."),
-
process_addr_pair(ProfNodeMap1, DynamicCallGraph, ProfNodeMap),
-
maybe_write_string(VVerbose, " done.\n"),
{ map__init(CycleMap) },
@@ -73,12 +76,11 @@
(
{ Dynamic = no }
->
- maybe_write_string(VVerbose, " done.\n"),
% maybe_write_string(VVerbose, "\t% Processing "),
% maybe_write_string(VVerbose, LibFile),
% maybe_write_string(VVerbose, "..."),
-
% process_library_callgraph(_, _),
+ % maybe_write_string(VVerbose, " done.\n"),
{ true }
;
@@ -90,7 +92,7 @@
% process_addr_decl:
-% Reads in the addrdecl.out file.
+% Reads in the Prof.Decl file.
% Builds the addrdecl map which associates label names(key) with
% label addresses.
% Also builds the prof_node_map which associates label addresses with
@@ -160,7 +162,7 @@
% process_addr:
-% Reads in the addr.out file and stores all the counts in the
+% Reads in the Prof.Counts file and stores all the counts in the
% prof_node structure. Also sums the total counts at the same time.
%
:- pred process_addr(prof_node_map, prof_node_map, int, int, int,
@@ -179,12 +181,20 @@
;
{ Result = error(Error) },
{ io__error_message(Error, ErrorMsg) },
- { string__append("error opening count file `", CountFile,
- Str0) },
- { string__append(Str0, "': ", Str1) },
- { string__append(Str1, ErrorMsg, Str2) },
- { string__append(Str2, "\n", ErrorStr) },
- { error(ErrorStr) }
+ io__write_string("\nWarning: error opening `"),
+ io__write_string(CountFile),
+ io__write_string("': "),
+ io__write_string(ErrorMsg),
+ io__write_string("\n"),
+ io__write_string("The generated profile will not include "),
+ io__write_string("timing information.\n\n"),
+ { TotalCounts = 0 },
+ { ProfNodeMap = ProfNodeMap0 },
+ % We can use any arbitrary values for Hertz and ClockTicks;
+ % the values here won't be used, since all the times will be
+ % zero.
+ { Hertz = 1 },
+ { ClockTicks = 1 }
).
:- pred process_addr_2(int, prof_node_map, int, prof_node_map,
@@ -229,7 +239,7 @@
% process_addr_pair:
-% Reads in the addrpair.out file and stores the data in the relevant
+% Reads in the Prof.CallPair file and stores the data in the relevant
% lists of the prof_node structure. Also calculates the number of times
% a predicate is called.
%
--
Fergus Henderson <fjh at cs.mu.oz.au> | "I have always known that the pursuit
WWW: <http://www.cs.mu.oz.au/~fjh> | of excellence is a lethal habit"
PGP: finger fjh at 128.250.37.3 | -- the last words of T. S. Garp.
More information about the developers
mailing list