[m-dev.] diff: fix profiling for MLDS grades
Fergus Henderson
fjh at cs.mu.OZ.AU
Tue Feb 6 17:21:05 AEDT 2001
For both the main and the release branches.
Estimated hours taken: 3
Fix SourceForge bug report #129892, "profiler map__lookup failed
in grade hlc.gc.memprof".
The remaining problem that was still causing failures for this
test case was that demangling isn't implemented for the MLDS
back-end. When symbols that the MLDS back end generates are
fed through the demangler, it demangles some distinct symbols
to the same name. This causes the profiler to abort, because
it assumes that each distinct symbol demangles to a different
name.
The fix is to turn off demangling when profiling programs
built in MLDS grades.
NEWS:
Mention that we haven't implemented symbol demangling
in the profiler for the MLDS back-end yet.
doc/user_guide.texi:
Document that for profiling of programs built with
`--high-level-code' you need to use the `--no-demangle'
option.
tools/test_mercury:
When testing the profiler in hl* grades,
pass `--no-demangle' to mprof, and compare with
*.mprof-exp2 rather than *.mprof-exp.
tests/benchmarks/poly.mprof-exp2:
New file. Contains alternative expected output for this test
case, to match what is output for grade hlc.gc.memprof (at -O2).
profiler/options.m:
The `--(no-)demangle' option is not a filename option,
so document it under the "Profiler options" section,
rather than the "Filename options" section.
Also fix a typo (s/Ouput/Output/) and a thinko
(s/unmangled/mangled/) in the description of that option.
Workspace: /home/venus/fjh/ws-venus/mercury
Index: NEWS
===================================================================
RCS file: /home/mercury1/repository/mercury/NEWS,v
retrieving revision 1.184.2.3
diff -u -d -r1.184.2.3 NEWS
--- NEWS 2001/02/05 16:14:24 1.184.2.3
+++ NEWS 2001/02/06 06:03:00
@@ -211,6 +211,7 @@
- calling copy/2 on higher-order terms
It also does not support the following implemention-specific
features that the old back-end supports:
+ - demangling of symbol names in the profiler
- fact tables for procedures with determinism `nondet' or `multi'
- the Mercury debugger (mdb)
- the Morphine trace analysis system
Index: doc/user_guide.texi
===================================================================
RCS file: /home/mercury1/repository/mercury/doc/user_guide.texi,v
retrieving revision 1.227.4.4
diff -u -d -r1.227.4.4 user_guide.texi
--- doc/user_guide.texi 2001/01/30 03:10:33 1.227.4.4
+++ doc/user_guide.texi 2001/02/06 05:44:11
@@ -2594,6 +2594,9 @@
redirect the output into a file with a command such as
@samp{mprof > mprof.out}.
+For programs built with @samp{--high-level-code}, you need to also
+pass the @samp{--no-demangle} option to @samp{mprof}.
+
@node Analysis of results
@section Analysis of results
Index: profiler/options.m
===================================================================
RCS file: /home/mercury1/repository/mercury/profiler/options.m,v
retrieving revision 1.14
diff -u -d -r1.14 options.m
--- profiler/options.m 2000/08/01 12:51:52 1.14
+++ profiler/options.m 2001/02/06 06:11:57
@@ -27,11 +27,12 @@
; profile_time
; profile_memory_words
; profile_memory_cells
+ ; demangle
+ % Filename options
; countfile
; pairfile
; declfile
; libraryfile
- ; demangle
% Miscellaneous Options
; help.
@@ -157,6 +158,8 @@
io__write_string("\t\tSame as `--profile memory-cells'.\n"),
io__write_string("\t-t\n"),
io__write_string("\t\tSame as `--profile time'.\n"),
+ io__write_string("\t--no-demangle\n"),
+ io__write_string("\t\tOutput the mangled predicate and function names.\n"),
io__write_string("\nFilename Options:\n"),
io__write_string("\t-C <file>, --count-file <file>\n"),
@@ -169,8 +172,6 @@
io__write_string("\t-L <file>, --library-callgraph <file>\n"),
io__write_string("\t\tName of the file which contains the call graph for\n"),
io__write_string("\t\tthe library modules.\n"),
- io__write_string("\t--no-demangle\n"),
- io__write_string("\t\tOuput the unmangled predicate and function names.\n"),
io__write_string("\nVerbosity Options:\n"),
Index: tools/test_mercury
===================================================================
RCS file: /home/mercury1/repository/mercury/tools/test_mercury,v
retrieving revision 1.126.2.3
diff -u -d -r1.126.2.3 test_mercury
--- tools/test_mercury 2001/01/07 02:16:01 1.126.2.3
+++ tools/test_mercury 2001/02/06 06:03:37
@@ -544,8 +544,21 @@
EXTRA_CFLAGS="$TEST_CFLAGS" \
EXTRA_MLFLAGS="$TEST_MLFLAGS" &&
LD_BIND_NOW=1 ./poly > poly.$grade.out &&
- mprof -v -m -c > poly.$grade.mprof 2>&1 &&
- { diff -u poly.mprof-exp poly.$grade.mprof || true; } &&
+ case $grade in
+ *hl*)
+ # for --high-level-code, we need to
+ # pass --no-demangle to mprof
+ mprof --no-demangle -v -m -c \
+ > poly.$grade.mprof 2>&1 &&
+ { diff -u poly.mprof-exp2 poly.$grade.mprof ||
+ true; }
+ ;;
+ *)
+ mprof -v -m -c > poly.$grade.mprof 2>&1 &&
+ { diff -u poly.mprof-exp poly.$grade.mprof ||
+ true; }
+ ;;
+ esac &&
cp Prof.CallPair poly.$grade.CallPair &&
cp Prof.MemoryWords poly.$grade.MemoryWords &&
cp Prof.MemoryCells poly.$grade.MemoryCells &&
Index: tests/benchmarks/poly.mprof-exp2
===================================================================
RCS file: poly.mprof-exp2
diff -N poly.mprof-exp2
--- /dev/null Fri Feb 2 11:58:58 2001
+++ poly.mprof-exp2 Tue Feb 6 17:05:58 2001
@@ -0,0 +1,332 @@
+% Processing input files... done
+% Building call graph... done
+% Propagating counts... done
+% Generating output... done
+*** profiling memory-words ***
+
+call graph profile:
+ Sorted on the %mem field.
+
+ procedure entries:
+
+index the index number of the procedure in the call graph
+ listing.
+
+%mem the percentage of the total allocated memory of
+ the program allocated by this procedure and its
+ descendents.
+
+self the number of kilowords actually allocated by
+ the procedure's own code.
+
+descendents the number of kilowords allocated by the
+ descendents of the current procedure.
+
+called the number of times the current procedure is
+ called (not counting self recursive calls).
+
+self the number of self recursive calls.
+
+name the name of the current procedure.
+
+index an index number to locate the function easily.
+
+
+
+ parent listings:
+
+self* the number of kilowords of the current procedure's self
+ memory due to calls from this parent.
+
+descendents* the number of kilowords of the current procedure's descendent
+ memory which is due to calls from this parent.
+
+called* the number of times the current procedure is called
+ by this parent.
+
+total the number of times this procedure is called by its parents.
+
+parents the name of this parent.
+
+index the index number of the parent procedure
+
+
+
+children listings:
+
+self* the number of kilowords of this child's self memory which is
+ due to being called by the current procedure.
+
+descendent* the number of kilowords of this child's descendent memory which
+ is due to the current procedure.
+
+called* the number of times this child is called by the current
+ procedure.
+
+total* the number of times this child is called by all procedures.
+
+children the name of this child.
+
+index the index number of the child.
+
+
+
+ called/total parents
+index %mem self descendents called+self name index
+ called/total children
+
+ 0.00 39.05 1/1 main_2_p_0 [2]
+[1] 99.9 0.00 39.05 1 poly__main1_1_p_0 [1]
+ 0.00 0.00 2/3433 poly__poly_add_3_p_0 <cycle 4> [8]
+ 0.00 39.01 1/1 poly__poly_exp_3_p_0 [3]
+
+-----------------------------------------------
+
+ <spontaneous>
+[2] 99.9 0.00 39.05 0 main_2_p_0 [2]
+ 0.00 0.00 1/2307 mercury__io__write_string_3_p_0 [22]
+ 0.00 39.05 1/1 poly__main1_1_p_0 [1]
+ 0.00 0.00 1/352 poly__print_poly_3_p_0 <cycle 2> [20]
+
+-----------------------------------------------
+
+ 5 poly__poly_exp_3_p_0 [3]
+ 0.00 39.01 1/1 poly__main1_1_p_0 [1]
+[3] 99.8 0.00 39.01 1+5 poly__poly_exp_3_p_0 [3]
+ 0.01 0.01 5/3930 poly__poly_mul_3_p_0 <cycle 3> [7]
+ 5 poly__poly_exp_3_p_0 [3]
+
+-----------------------------------------------
+
+ 932 poly__term_mul_3_p_0 <cycle 3> [4]
+ 283 poly__poly_mul_3_p_0 <cycle 3> [7]
+[4] 48.2 0.00 18.85 283+932 poly__term_mul_3_p_0 <cycle 3> [4]
+ 10.32 10.32 932/1355 poly__term_add_3_p_0 <cycle 4> [5]
+ 932 poly__single_term_mul_3_p_0 <cycle 3> [6]
+ 932 poly__term_mul_3_p_0 <cycle 3> [4]
+
+-----------------------------------------------
+
+ 4077 poly__term_add_3_p_0 <cycle 4> [5]
+ 423 poly__poly_add_3_p_0 <cycle 4> [8]
+ 15.01 15.01 932/1355 poly__term_mul_3_p_0 <cycle 3> [4]
+[5] 38.4 15.01 15.01 1355+4077 poly__term_add_3_p_0 <cycle 4> [5]
+ 3428 poly__poly_add_3_p_0 <cycle 4> [8]
+ 4077 poly__term_add_3_p_0 <cycle 4> [5]
+
+-----------------------------------------------
+
+ 3129 poly__single_term_mul_3_p_0 <cycle 3> [6]
+ 932 poly__term_mul_3_p_0 <cycle 3> [4]
+[6] 32.0 12.52 12.52 932+3129 poly__single_term_mul_3_p_0 <cycle 3> [6]
+ 3129 poly__poly_mul_3_p_0 <cycle 3> [7]
+ 3129 poly__single_term_mul_3_p_0 <cycle 3> [6]
+
+-----------------------------------------------
+
+ 796 poly__mul_through_3_p_0 <cycle 3> [9]
+ 3129 poly__single_term_mul_3_p_0 <cycle 3> [6]
+ 4.46 4.46 5/3930 poly__poly_exp_3_p_0 [3]
+[7] 11.4 4.46 4.46 3930 poly__poly_mul_3_p_0 <cycle 3> [7]
+ 251 poly__mul_through_3_p_0 <cycle 3> [9]
+ 283 poly__term_mul_3_p_0 <cycle 3> [4]
+
+-----------------------------------------------
+
+ 3 poly__add_to_order_zero_term_3_p_0 <cycle 4> [13]
+ 3428 poly__term_add_3_p_0 <cycle 4> [5]
+ 3.86 3.86 2/3433 poly__main1_1_p_0 [1]
+[8] 9.9 3.86 3.86 3433 poly__poly_add_3_p_0 <cycle 4> [8]
+ 5 poly__add_to_order_zero_term_3_p_0 <cycle 4> [13]
+ 423 poly__term_add_3_p_0 <cycle 4> [5]
+
+-----------------------------------------------
+
+ 796 poly__mul_through_3_p_0 <cycle 3> [9]
+ 251 poly__poly_mul_3_p_0 <cycle 3> [7]
+[9] 8.1 3.18 3.18 251+796 poly__mul_through_3_p_0 <cycle 3> [9]
+ 796 poly__poly_mul_3_p_0 <cycle 3> [7]
+ 796 poly__mul_through_3_p_0 <cycle 3> [9]
+
+-----------------------------------------------
+
+ <spontaneous>
+[10] 0.1 0.00 0.02 0 mercury__io__init_state_2_p_0 [10]
+ 0.00 0.02 1/1 mercury__io__insert_std_stream_names_2_p_0 [11]
+ 0.00 0.00 1/1 mercury__std_util__type_to_univ_2_p_0 [16]
+ 0.00 0.00 1/1 mercury__tree234__init_1_p_0 [23]
+
+-----------------------------------------------
+
+ 0.00 0.02 1/1 mercury__io__init_state_2_p_0 [10]
+[11] 0.1 0.00 0.02 1 mercury__io__insert_std_stream_names_2_p_0 [11]
+ 0.00 0.02 3/3 mercury__tree234__set_4_p_1 [12]
+
+-----------------------------------------------
+
+ 0.00 0.02 3/3 mercury__io__insert_std_stream_names_2_p_0 [11]
+[12] 0.1 0.00 0.02 3 mercury__tree234__set_4_p_1 [12]
+ 0.01 0.01 1/1 mercury__tree234__set2__ua1_4_p_0 [15]
+ 0.01 0.01 1/1 mercury__tree234__set3__ua1_4_p_0 [14]
+
+-----------------------------------------------
+
+ 5 poly__poly_add_3_p_0 <cycle 4> [8]
+[13] 0.1 0.02 0.02 5 poly__add_to_order_zero_term_3_p_0 <cycle 4> [13]
+ 3 poly__poly_add_3_p_0 <cycle 4> [8]
+
+-----------------------------------------------
+
+ 0.01 0.01 1/1 mercury__tree234__set_4_p_1 [12]
+[14] 0.0 0.01 0.01 1 mercury__tree234__set3__ua1_4_p_0 [14]
+ 0.00 0.00 2/3 mercury__builtin__compare_3_p_0 [24]
+
+-----------------------------------------------
+
+ 0.01 0.01 1/1 mercury__tree234__set_4_p_1 [12]
+[15] 0.0 0.01 0.01 1 mercury__tree234__set2__ua1_4_p_0 [15]
+ 0.00 0.00 1/3 mercury__builtin__compare_3_p_0 [24]
+
+-----------------------------------------------
+
+ 0.00 0.00 1/1 mercury__io__init_state_2_p_0 [10]
+[16] 0.0 0.00 0.00 1 mercury__std_util__type_to_univ_2_p_0 [16]
+
+-----------------------------------------------
+
+ 351 poly__print_terms_2_3_p_0 <cycle 2> [18]
+[17] 0.0 0.00 0.00 351 poly__print_term_3_p_0 <cycle 2> [17]
+ 0.00 0.00 351/637 mercury__io__write_int_3_p_0 [21]
+ 0.00 0.00 1053/2307 mercury__io__write_string_3_p_0 [22]
+ 351 poly__print_poly_3_p_0 <cycle 2> [20]
+
+-----------------------------------------------
+
+ 66 poly__print_terms_3_p_0 <cycle 2> [19]
+[18] 0.0 0.00 0.00 66 poly__print_terms_2_3_p_0 <cycle 2> [18]
+ 0.00 0.00 285/2307 mercury__io__write_string_3_p_0 [22]
+ 351 poly__print_term_3_p_0 <cycle 2> [17]
+
+-----------------------------------------------
+
+ 66 poly__print_poly_3_p_0 <cycle 2> [20]
+[19] 0.0 0.00 0.00 66 poly__print_terms_3_p_0 <cycle 2> [19]
+ 0.00 0.00 132/2307 mercury__io__write_string_3_p_0 [22]
+ 66 poly__print_terms_2_3_p_0 <cycle 2> [18]
+
+-----------------------------------------------
+
+ 351 poly__print_term_3_p_0 <cycle 2> [17]
+ 0.00 0.00 1/352 main_2_p_0 [2]
+[20] 0.0 0.00 0.00 352 poly__print_poly_3_p_0 <cycle 2> [20]
+ 0.00 0.00 286/637 mercury__io__write_int_3_p_0 [21]
+ 0.00 0.00 836/2307 mercury__io__write_string_3_p_0 [22]
+ 66 poly__print_terms_3_p_0 <cycle 2> [19]
+
+-----------------------------------------------
+
+ 0.00 0.00 286/637 poly__print_poly_3_p_0 <cycle 2> [20]
+ 0.00 0.00 351/637 poly__print_term_3_p_0 <cycle 2> [17]
+[21] 0.0 0.00 0.00 637 mercury__io__write_int_3_p_0 [21]
+
+-----------------------------------------------
+
+ 0.00 0.00 1/2307 main_2_p_0 [2]
+ 0.00 0.00 836/2307 poly__print_poly_3_p_0 <cycle 2> [20]
+ 0.00 0.00 1053/2307 poly__print_term_3_p_0 <cycle 2> [17]
+ 0.00 0.00 285/2307 poly__print_terms_2_3_p_0 <cycle 2> [18]
+ 0.00 0.00 132/2307 poly__print_terms_3_p_0 <cycle 2> [19]
+[22] 0.0 0.00 0.00 2307 mercury__io__write_string_3_p_0 [22]
+
+-----------------------------------------------
+
+ 0.00 0.00 1/1 mercury__io__init_state_2_p_0 [10]
+[23] 0.0 0.00 0.00 1 mercury__tree234__init_1_p_0 [23]
+
+-----------------------------------------------
+
+ 0.00 0.00 1/3 mercury__tree234__set2__ua1_4_p_0 [15]
+ 0.00 0.00 2/3 mercury__tree234__set3__ua1_4_p_0 [14]
+[24] 0.0 0.00 0.00 3 mercury__builtin__compare_3_p_0 [24]
+
+-----------------------------------------------
+
+
+flat profile:
+
+% the percentage of total allocated memory of the program
+mem used by this procedure.
+
+cumulative the total number of kilowords for the current procedure and
+k-words the ones listed above it.
+
+self the number of kilowords accounted for by this procedure alone.
+k-words The listing is sorted on this row.
+
+calls the number of times this procedure was called.
+
+self the average number of words allocated by
+wds/call this procedure per call.
+
+total the average number of words allocated by this procedure and its
+wds/call descendents per call.
+
+name the name of the procedure followed by its index number.
+
+ % cumulative self self total
+ mem k-words k-words calls wds/call wds/call name
+ 38.4 15.01 15.01 5432 2.76 2.76 poly__term_add_3_p_0 <cycle 4> [5]
+ 32.0 27.53 12.52 4061 3.08 3.08 poly__single_term_mul_3_p_0 <cycle 3> [6]
+ 11.4 31.99 4.46 3930 1.14 1.14 poly__poly_mul_3_p_0 <cycle 3> [7]
+ 9.9 35.85 3.86 3433 1.12 1.12 poly__poly_add_3_p_0 <cycle 4> [8]
+ 8.1 39.03 3.18 1047 3.04 3.04 poly__mul_through_3_p_0 <cycle 3> [9]
+ 0.1 39.05 0.02 5 4.00 4.00 poly__add_to_order_zero_term_3_p_0 <cycle 4> [13]
+ 0.0 39.06 0.01 1 10.00 10.00 mercury__tree234__set3__ua1_4_p_0 [14]
+ 0.0 39.07 0.01 1 7.00 7.00 mercury__tree234__set2__ua1_4_p_0 [15]
+ 0.0 39.08 0.00 3 1.33 7.00 mercury__tree234__set_4_p_1 [12]
+ 0.0 39.08 0.00 1 2.00 2.00 mercury__std_util__type_to_univ_2_p_0 [16]
+ 0.0 39.08 0.00 2307 0.00 0.00 mercury__io__write_string_3_p_0 [22]
+ 0.0 39.08 0.00 637 0.00 0.00 mercury__io__write_int_3_p_0 [21]
+ 0.0 39.08 0.00 352 0.00 0.00 poly__print_poly_3_p_0 <cycle 2> [20]
+ 0.0 39.08 0.00 351 0.00 0.00 poly__print_term_3_p_0 <cycle 2> [17]
+ 0.0 39.08 0.00 1215 0.00 15.51 poly__term_mul_3_p_0 <cycle 3> [4]
+ 0.0 39.08 0.00 66 0.00 0.00 poly__print_terms_2_3_p_0 <cycle 2> [18]
+ 0.0 39.08 0.00 66 0.00 0.00 poly__print_terms_3_p_0 <cycle 2> [19]
+ 0.0 39.08 0.00 3 0.00 0.00 mercury__builtin__compare_3_p_0 [24]
+ 0.0 39.08 0.00 6 0.00 6502.42 poly__poly_exp_3_p_0 [3]
+ 0.0 39.08 0.00 1 0.00 39055.00 poly__main1_1_p_0 [1]
+ 0.0 39.08 0.00 1 0.00 21.00 mercury__io__insert_std_stream_names_2_p_0 [11]
+ 0.0 39.08 0.00 1 0.00 0.00 mercury__tree234__init_1_p_0 [23]
+ 0.0 39.08 0.00 0 0.00 0.00 main_2_p_0 [2]
+ 0.0 39.08 0.00 0 0.00 0.00 mercury__io__init_state_2_p_0 [10]
+
+
+
+alphabetic listing:
+
+[2] main_2_p_0
+[24] mercury__builtin__compare_3_p_0
+[10] mercury__io__init_state_2_p_0
+[11] mercury__io__insert_std_stream_names_2_p_0
+[21] mercury__io__write_int_3_p_0
+[22] mercury__io__write_string_3_p_0
+[16] mercury__std_util__type_to_univ_2_p_0
+[23] mercury__tree234__init_1_p_0
+[15] mercury__tree234__set2__ua1_4_p_0
+[14] mercury__tree234__set3__ua1_4_p_0
+[12] mercury__tree234__set_4_p_1
+[13] poly__add_to_order_zero_term_3_p_0
+[1] poly__main1_1_p_0
+[9] poly__mul_through_3_p_0
+[8] poly__poly_add_3_p_0
+[3] poly__poly_exp_3_p_0
+[7] poly__poly_mul_3_p_0
+[20] poly__print_poly_3_p_0
+[17] poly__print_term_3_p_0
+[18] poly__print_terms_2_3_p_0
+[19] poly__print_terms_3_p_0
+[6] poly__single_term_mul_3_p_0
+[5] poly__term_add_3_p_0
+[4] poly__term_mul_3_p_0
+
+
--
Fergus Henderson <fjh at cs.mu.oz.au> | "I have always known that the pursuit
| of excellence is a lethal habit"
WWW: <http://www.cs.mu.oz.au/~fjh> | -- the last words of T. S. Garp.
--------------------------------------------------------------------------
mercury-developers mailing list
Post messages to: mercury-developers at cs.mu.oz.au
Administrative Queries: owner-mercury-developers at cs.mu.oz.au
Subscriptions: mercury-developers-request at cs.mu.oz.au
--------------------------------------------------------------------------
More information about the developers
mailing list