Commit d7933cbc authored by Ömer Sinan Ağacan's avatar Ömer Sinan Ağacan
Browse files

Show sources of cost centers in .prof

This fixes the problem with duplicate cost-centre names that was
reported a couple of times before. When a module implements a typeclass
multiple times for different types, methods of different implementations
get same cost-centre names and are reported like this:

    COST CENTRE MODULE            %time %alloc

    CAF         GHC.IO.Handle.FD    0.0   32.8
    CAF         GHC.Read            0.0    1.0
    CAF         GHC.IO.Encoding     0.0    1.8
    showsPrec   Main                0.0    1.2
    readPrec    Main                0.0   19.4
    readPrec    Main                0.0   20.5
    main        Main                0.0   20.2

                                            individual      inherited
    COST CENTRE  MODULE  no.     entries  %time %alloc   %time %alloc

    MAIN         MAIN     53          0    0.0    0.2     0.0  100.0
     CAF         Main    105          0    0.0    0.3     0.0   62.5
      readPrec   Main    109          1    0.0    0.6     0.0    0.6
      readPrec   Main    107          1    0.0    0.6     0.0    0.6
      main       Main    106          1    0.0   20.2     0.0   61.0
       ==        Main    114          1    0.0    0.0     0.0    0.0
       ==        Main    113          1    0.0    0.0     0.0    0.0
       showsPrec Main    112          2    0.0    1.2     0.0    1.2
       showsPrec Main    111          2    0.0    0.9     0.0    0.9
       readPrec  Main    110          0    0.0   18.8     0.0   18.8
       readPrec  Main    108          0    0.0   19.9     0.0   19.9

It's not possible to tell from the report which `==` took how long. This
patch adds one more column at the cost of making outputs wider. The
report now looks like this:

    COST CENTRE MODULE           SRC                       %time %alloc

    CAF         GHC.IO.Handle.FD <entire-module>             0.0   32.9
    CAF         GHC.IO.Encoding  <entire-module>             0.0    1.8
    CAF         GHC.Read         <entire-module>             0.0    1.0
    showsPrec   Main             Main_1.hs:7:19-22           0.0    1.2
    readPrec    Main             Main_1.hs:7:13-16           0.0   19.5
    readPrec    Main             Main_1.hs:4:13-16           0.0   20.5
    main        Main             Main_1.hs:(10,1)-(20,20)    0.0   20.2

                                                                       individual      inherited
    COST CENTRE  MODULE        SRC                      no. entries  %time %alloc   %time %alloc

    MAIN         MAIN          <built-in>                53      0    0.0    0.2     0.0  100.0
     CAF         Main          <entire-module>          105      0    0.0    0.3     0.0   62.5
      readPrec   Main          Main_1.hs:7:13-16        109      1    0.0    0.6     0.0    0.6
      readPrec   Main          Main_1.hs:4:13-16        107      1    0.0    0.6     0.0    0.6
      main       Main          Main_1.hs:(10,1)-(20,20) 106      1    0.0   20.2     0.0   61.0
       ==        Main          Main_1.hs:7:25-26        114      1    0.0    0.0     0.0    0.0
       ==        Main          Main_1.hs:4:25-26        113      1    0.0    0.0     0.0    0.0
       showsPrec Main          Main_1.hs:7:19-22        112      2    0.0    1.2     0.0    1.2
       showsPrec Main          Main_1.hs:4:19-22        111      2    0.0    0.9     0.0    0.9
       readPrec  Main          Main_1.hs:7:13-16        110      0    0.0   18.8     0.0   18.8
       readPrec  Main          Main_1.hs:4:13-16        108      0    0.0   19.9     0.0   19.9
     CAF         Text.Read.Lex <entire-module>          102      0    0.0    0.5     0.0    0.5

To fix failing test cases because of different orderings of cost centres
(e.g. optimized and non-optimized build printing in different order),
with this patch we also start sorting cost centres before printing. The
order depends on 1) entries (more entered cost centres come first) 2)
names (using strcmp() on cost centre names).

Reviewers: simonmar, austin, erikd, bgamari

Reviewed By: simonmar, bgamari

Subscribers: thomie

Differential Revision: https://phabricator.haskell.org/D2282

GHC Trac Issues: #11543, #8473, #7105
parent 80cf4cf0
......@@ -119,16 +119,19 @@ static void findCCSMaxLens ( CostCentreStack *ccs,
uint32_t indent,
uint32_t *max_label_len,
uint32_t *max_module_len,
uint32_t *max_src_len,
uint32_t *max_id_len );
static void logCCS ( CostCentreStack *ccs,
uint32_t indent,
uint32_t max_label_len,
uint32_t max_module_len,
uint32_t max_src_len,
uint32_t max_id_len );
static void reportCCS ( CostCentreStack *ccs );
static CostCentreStack * checkLoop ( CostCentreStack *ccs,
CostCentre *cc );
static CostCentreStack * pruneCCSTree ( CostCentreStack *ccs );
static void sortCCSTree ( CostCentreStack *ccs );
static CostCentreStack * actualPush ( CostCentreStack *, CostCentre * );
static CostCentreStack * isInIndexTable ( IndexTable *, CostCentre * );
static IndexTable * addToIndexTable ( IndexTable *, CostCentreStack *,
......@@ -764,13 +767,14 @@ static void
reportPerCCCosts( void )
{
CostCentre *cc, *next;
uint32_t max_label_len, max_module_len;
uint32_t max_label_len, max_module_len, max_src_len;
aggregateCCCosts(CCS_MAIN);
sorted_cc_list = NULL;
max_label_len = 11; // no shorter than the "COST CENTRE" header
max_module_len = 6; // no shorter than the "MODULE" header
max_src_len = 3; // no shorter than the "SRC" header
for (cc = CC_LIST; cc != NULL; cc = next) {
next = cc->link;
......@@ -781,10 +785,12 @@ reportPerCCCosts( void )
max_label_len = stg_max(strlen_utf8(cc->label), max_label_len);
max_module_len = stg_max(strlen_utf8(cc->module), max_module_len);
max_src_len = stg_max(strlen_utf8(cc->srcloc), max_src_len);
}
}
fprintf(prof_file, "%-*s %-*s", max_label_len, "COST CENTRE", max_module_len, "MODULE");
fprintf(prof_file, "%-*s %-*s %-*s",
max_label_len, "COST CENTRE", max_module_len, "MODULE", max_src_len, "SRC");
fprintf(prof_file, " %6s %6s", "%time", "%alloc");
if (RtsFlags.CcFlags.doCostCentres >= COST_CENTRES_VERBOSE) {
fprintf(prof_file, " %5s %9s", "ticks", "bytes");
......@@ -795,11 +801,13 @@ reportPerCCCosts( void )
if (ignoreCC(cc)) {
continue;
}
fprintf(prof_file, "%s%*s %s%*s",
fprintf(prof_file, "%s%*s %s%*s %s%*s",
cc->label,
max_label_len - strlen_utf8(cc->label), "",
cc->module,
max_module_len - strlen_utf8(cc->module), "");
max_module_len - strlen_utf8(cc->module), "",
cc->srcloc,
max_src_len - strlen_utf8(cc->srcloc), "");
fprintf(prof_file, " %6.1f %6.1f",
total_prof_ticks == 0 ? 0.0 : (cc->time_ticks / (StgFloat) total_prof_ticks * 100),
......@@ -823,17 +831,19 @@ reportPerCCCosts( void )
static void
fprintHeader( uint32_t max_label_len, uint32_t max_module_len,
uint32_t max_id_len )
uint32_t max_src_len, uint32_t max_id_len )
{
fprintf(prof_file, "%-*s %-*s %-*s %11s %12s %12s\n",
fprintf(prof_file, "%-*s %-*s %-*s %-*s %11s %12s %12s\n",
max_label_len, "",
max_module_len, "",
max_src_len, "",
max_id_len, "",
"", "individual", "inherited");
fprintf(prof_file, "%-*s %-*s %-*s",
fprintf(prof_file, "%-*s %-*s %-*s %-*s",
max_label_len, "COST CENTRE",
max_module_len, "MODULE",
max_src_len, "SRC",
max_id_len, "no.");
fprintf(prof_file, " %11s %5s %6s %5s %6s",
......@@ -890,7 +900,9 @@ reportCCSProfiling( void )
inheritCosts(CCS_MAIN);
reportCCS(pruneCCSTree(CCS_MAIN));
CostCentreStack *stack = pruneCCSTree(CCS_MAIN);
sortCCSTree(stack);
reportCCS(stack);
}
static uint32_t
......@@ -911,7 +923,7 @@ numDigits(StgInt i) {
static void
findCCSMaxLens(CostCentreStack *ccs, uint32_t indent, uint32_t *max_label_len,
uint32_t *max_module_len, uint32_t *max_id_len) {
uint32_t *max_module_len, uint32_t *max_src_len, uint32_t *max_id_len) {
CostCentre *cc;
IndexTable *i;
......@@ -919,19 +931,21 @@ findCCSMaxLens(CostCentreStack *ccs, uint32_t indent, uint32_t *max_label_len,
*max_label_len = stg_max(*max_label_len, indent + strlen_utf8(cc->label));
*max_module_len = stg_max(*max_module_len, strlen_utf8(cc->module));
*max_src_len = stg_max(*max_src_len, strlen_utf8(cc->srcloc));
*max_id_len = stg_max(*max_id_len, numDigits(ccs->ccsID));
for (i = ccs->indexTable; i != 0; i = i->next) {
if (!i->back_edge) {
findCCSMaxLens(i->ccs, indent+1,
max_label_len, max_module_len, max_id_len);
max_label_len, max_module_len, max_src_len, max_id_len);
}
}
}
static void
logCCS(CostCentreStack *ccs, uint32_t indent,
uint32_t max_label_len, uint32_t max_module_len, uint32_t max_id_len)
uint32_t max_label_len, uint32_t max_module_len,
uint32_t max_src_len, uint32_t max_id_len)
{
CostCentre *cc;
IndexTable *i;
......@@ -944,12 +958,14 @@ logCCS(CostCentreStack *ccs, uint32_t indent,
/* force printing of *all* cost centres if -Pa */
{
fprintf(prof_file, "%-*s%s%*s %s%*s",
fprintf(prof_file, "%*s%s%*s %s%*s %s%*s",
indent, "",
cc->label,
max_label_len-indent - strlen_utf8(cc->label), "",
cc->module,
max_module_len - strlen_utf8(cc->module), "");
max_module_len - strlen_utf8(cc->module), "",
cc->srcloc,
max_src_len - strlen_utf8(cc->srcloc), "");
fprintf(prof_file,
" %*" FMT_Int "%11" FMT_Word64 " %5.1f %5.1f %5.1f %5.1f",
......@@ -969,7 +985,8 @@ logCCS(CostCentreStack *ccs, uint32_t indent,
for (i = ccs->indexTable; i != 0; i = i->next) {
if (!i->back_edge) {
logCCS(i->ccs, indent+1, max_label_len, max_module_len, max_id_len);
logCCS(i->ccs, indent+1,
max_label_len, max_module_len, max_src_len, max_id_len);
}
}
}
......@@ -977,16 +994,18 @@ logCCS(CostCentreStack *ccs, uint32_t indent,
static void
reportCCS(CostCentreStack *ccs)
{
uint32_t max_label_len, max_module_len, max_id_len;
uint32_t max_label_len, max_module_len, max_src_len, max_id_len;
max_label_len = 11; // no shorter than "COST CENTRE" header
max_module_len = 6; // no shorter than "MODULE" header
max_src_len = 3; // no shorter than "SRC" header
max_id_len = 3; // no shorter than "no." header
findCCSMaxLens(ccs, 0, &max_label_len, &max_module_len, &max_id_len);
findCCSMaxLens(ccs, 0,
&max_label_len, &max_module_len, &max_src_len, &max_id_len);
fprintHeader(max_label_len, max_module_len, max_id_len);
logCCS(ccs, 0, max_label_len, max_module_len, max_id_len);
fprintHeader(max_label_len, max_module_len, max_src_len, max_id_len);
logCCS(ccs, 0, max_label_len, max_module_len, max_src_len, max_id_len);
}
......@@ -1064,6 +1083,63 @@ pruneCCSTree (CostCentreStack *ccs)
}
}
static IndexTable*
insertIndexTableInSortedList(IndexTable* tbl, IndexTable* sortedList)
{
StgWord tbl_ticks = tbl->ccs->scc_count;
char* tbl_label = tbl->ccs->cc->label;
IndexTable *prev = NULL;
IndexTable *cursor = sortedList;
while (cursor != NULL) {
StgWord cursor_ticks = cursor->ccs->scc_count;
char* cursor_label = cursor->ccs->cc->label;
if (tbl_ticks > cursor_ticks ||
(tbl_ticks == cursor_ticks && strcmp(tbl_label, cursor_label) < 0)) {
if (prev == NULL) {
tbl->next = sortedList;
return tbl;
} else {
prev->next = tbl;
tbl->next = cursor;
return sortedList;
}
} else {
prev = cursor;
cursor = cursor->next;
}
}
prev->next = tbl;
return sortedList;
}
static void
sortCCSTree(CostCentreStack *ccs)
{
if (ccs->indexTable == NULL) return;
for (IndexTable *tbl = ccs->indexTable; tbl != NULL; tbl = tbl->next)
if (!tbl->back_edge)
sortCCSTree(tbl->ccs);
IndexTable *sortedList = ccs->indexTable;
IndexTable *nonSortedList = sortedList->next;
sortedList->next = NULL;
while (nonSortedList != NULL)
{
IndexTable *nonSortedTail = nonSortedList->next;
nonSortedList->next = NULL;
sortedList = insertIndexTableInSortedList(nonSortedList, sortedList);
nonSortedList = nonSortedTail;
}
ccs->indexTable = sortedList;
}
void
fprintCCS( FILE *f, CostCentreStack *ccs )
{
......
......@@ -1763,21 +1763,38 @@ def normalise_prof (str):
str = re.sub('[ \t]*main[ \t]+Main.*\n','',str)
# We have somthing like this:
# MAIN MAIN 101 0 0.0 0.0 100.0 100.0
# k Main 204 1 0.0 0.0 0.0 0.0
# foo Main 205 1 0.0 0.0 0.0 0.0
# foo.bar Main 207 1 0.0 0.0 0.0 0.0
# then we remove all the specific profiling data, leaving only the
# cost centre name, module, and entries, to end up with this:
# MAIN MAIN 0
# k Main 1
# foo Main 1
# foo.bar Main 1
str = re.sub('\n([ \t]*[^ \t]+)([ \t]+[^ \t]+)([ \t]+\\d+)([ \t]+\\d+)[ \t]+([\\d\\.]+)[ \t]+([\\d\\.]+)[ \t]+([\\d\\.]+)[ \t]+([\\d\\.]+)','\n\\1 \\2 \\4',str)
#
# MAIN MAIN <built-in> 53 0 0.0 0.2 0.0 100.0
# CAF Main <entire-module> 105 0 0.0 0.3 0.0 62.5
# readPrec Main Main_1.hs:7:13-16 109 1 0.0 0.6 0.0 0.6
# readPrec Main Main_1.hs:4:13-16 107 1 0.0 0.6 0.0 0.6
# main Main Main_1.hs:(10,1)-(20,20) 106 1 0.0 20.2 0.0 61.0
# == Main Main_1.hs:7:25-26 114 1 0.0 0.0 0.0 0.0
# == Main Main_1.hs:4:25-26 113 1 0.0 0.0 0.0 0.0
# showsPrec Main Main_1.hs:7:19-22 112 2 0.0 1.2 0.0 1.2
# showsPrec Main Main_1.hs:4:19-22 111 2 0.0 0.9 0.0 0.9
# readPrec Main Main_1.hs:7:13-16 110 0 0.0 18.8 0.0 18.8
# readPrec Main Main_1.hs:4:13-16 108 0 0.0 19.9 0.0 19.9
#
# then we remove all the specific profiling data, leaving only the cost
# centre name, module, src, and entries, to end up with this: (modulo
# whitespace between columns)
#
# MAIN MAIN <built-in> 0
# readPrec Main Main_1.hs:7:13-16 1
# readPrec Main Main_1.hs:4:13-16 1
# == Main Main_1.hs:7:25-26 1
# == Main Main_1.hs:4:25-26 1
# showsPrec Main Main_1.hs:7:19-22 2
# showsPrec Main Main_1.hs:4:19-22 2
# readPrec Main Main_1.hs:7:13-16 0
# readPrec Main Main_1.hs:4:13-16 0
# Split 9 whitespace-separated groups, take columns 1 (cost-centre), 2
# (module), 3 (src), and 5 (entries). SCC names can't have whitespace, so
# this works fine.
str = re.sub(r'\s*(\S+)\s*(\S+)\s*(\S+)\s*(\S+)\s*(\S+)\s*(\S+)\s*(\S+)\s*(\S+)\s*(\S+)\s*',
'\\1 \\2 \\3 \\5\n', str)
return str
def normalise_slashes_( str ):
......
Wed Jan 27 08:12 2016 Time and Allocation Profiling Report (Final)
Sat Jun 4 11:59 2016 Time and Allocation Profiling Report (Final)
T2552 +RTS -hc -p -RTS
total time = 0.01 secs (5 ticks @ 1000 us, 1 processor)
total alloc = 123,466,024 bytes (excludes profiling overheads)
total time = 0.09 secs (90 ticks @ 1000 us, 1 processor)
total alloc = 123,465,848 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
COST CENTRE MODULE SRC %time %alloc
fib1.fib1'.nfib Main 80.0 33.3
MAIN MAIN 20.0 0.0
fib2'.nfib Main 0.0 33.3
fib3'.nfib Main 0.0 33.3
fib1.fib1'.nfib Main T2552.hs:5:9-61 37.8 33.3
fib2'.nfib Main T2552.hs:10:5-57 31.1 33.3
fib3'.nfib Main T2552.hs:15:5-57 31.1 33.3
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
individual inherited
COST CENTRE MODULE SRC no. entries %time %alloc %time %alloc
MAIN MAIN 105 0 20.0 0.0 100.0 100.0
main Main 211 0 0.0 0.0 0.0 0.0
CAF Main 209 0 0.0 0.0 80.0 100.0
main Main 210 1 0.0 0.0 80.0 100.0
fib3' Main 220 1 0.0 0.0 0.0 33.3
fib3'.nfib Main 221 1028457 0.0 33.3 0.0 33.3
fib3 Main 219 1 0.0 0.0 0.0 0.0
fib2 Main 216 1 0.0 0.0 0.0 33.3
fib2' Main 217 1 0.0 0.0 0.0 33.3
fib2'.nfib Main 218 1028457 0.0 33.3 0.0 33.3
fib1 Main 212 1 0.0 0.0 80.0 33.3
fib1.fib1' Main 213 1 0.0 0.0 80.0 33.3
nfib' Main 214 1 0.0 0.0 80.0 33.3
fib1.fib1'.nfib Main 215 1028457 80.0 33.3 80.0 33.3
CAF GHC.Conc.Signal 203 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding 193 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv 191 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.FD 183 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.Text 181 0 0.0 0.0 0.0 0.0
MAIN MAIN <built-in> 45 0 0.0 0.0 100.0 100.0
CAF Main <entire-module> 89 0 0.0 0.0 100.0 100.0
main Main T2552.hs:(17,1)-(20,17) 90 1 0.0 0.0 100.0 100.0
fib1 Main T2552.hs:(1,1)-(5,61) 92 1 0.0 0.0 37.8 33.3
fib1.fib1' Main T2552.hs:(3,5)-(5,61) 93 1 0.0 0.0 37.8 33.3
nfib' Main T2552.hs:3:35-40 94 1 0.0 0.0 37.8 33.3
fib1.fib1'.nfib Main T2552.hs:5:9-61 95 1028457 37.8 33.3 37.8 33.3
fib2 Main T2552.hs:7:1-16 96 1 0.0 0.0 31.1 33.3
fib2' Main T2552.hs:(8,1)-(10,57) 97 1 0.0 0.0 31.1 33.3
fib2'.nfib Main T2552.hs:10:5-57 98 1028457 31.1 33.3 31.1 33.3
fib3 Main T2552.hs:12:1-12 99 1 0.0 0.0 0.0 0.0
fib3' Main T2552.hs:(13,1)-(15,57) 100 1 0.0 0.0 31.1 33.3
fib3'.nfib Main T2552.hs:15:5-57 101 1028457 31.1 33.3 31.1 33.3
CAF GHC.IO.Handle.FD <entire-module> 84 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.Text <entire-module> 83 0 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal <entire-module> 81 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding <entire-module> 78 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv <entire-module> 64 0 0.0 0.0 0.0 0.0
main Main T2552.hs:(17,1)-(20,17) 91 0 0.0 0.0 0.0 0.0
Thu Apr 2 19:44 2015 Time and Allocation Profiling Report (Final)
Fri Jun 3 10:46 2016 Time and Allocation Profiling Report (Final)
T5559 +RTS -p -RTS
total time = 0.04 secs (36 ticks @ 1000 us, 1 processor)
total alloc = 57,359,016 bytes (excludes profiling overheads)
total time = 0.04 secs (39 ticks @ 1000 us, 1 processor)
total alloc = 57,359,352 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
COST CENTRE MODULE SRC %time %alloc
føb Main 97.2 99.9
MAIN MAIN 2.8 0.0
føb Main T5559.hs:(2,1)-(5,38) 100.0 99.9
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
individual inherited
COST CENTRE MODULE SRC no. entries %time %alloc %time %alloc
MAIN MAIN 99 0 2.8 0.0 100.0 100.0
CAF Main 197 0 0.0 0.0 97.2 99.9
main Main 198 1 0.0 0.0 97.2 99.9
føb Main 199 392835 97.2 99.9 97.2 99.9
CAF GHC.Conc.Signal 179 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding 163 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv 161 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.FD 152 0 0.0 0.1 0.0 0.1
CAF GHC.IO.Handle.Text 150 0 0.0 0.0 0.0 0.0
MAIN MAIN <built-in> 45 0 0.0 0.0 100.0 100.0
CAF Main <entire-module> 89 0 0.0 0.0 100.0 99.9
main Main T5559.hs:8:1-21 90 1 0.0 0.0 100.0 99.9
føb Main T5559.hs:(2,1)-(5,38) 91 392835 100.0 99.9 100.0 99.9
CAF GHC.Conc.Signal <entire-module> 80 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding <entire-module> 77 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.FD <entire-module> 75 0 0.0 0.1 0.0 0.1
CAF GHC.IO.Handle.Text <entire-module> 73 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv <entire-module> 56 0 0.0 0.0 0.0 0.0
Wed Jan 27 08:16 2016 Time and Allocation Profiling Report (Final)
Sat Jun 4 11:59 2016 Time and Allocation Profiling Report (Final)
T5654b-O0 +RTS -p -RTS
total time = 0.00 secs (0 ticks @ 1000 us, 1 processor)
total alloc = 39,248 bytes (excludes profiling overheads)
total alloc = 39,112 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
COST CENTRE MODULE SRC %time %alloc
CAF GHC.IO.Handle.FD 0.0 88.0
CAF GHC.IO.Encoding 0.0 7.3
CAF GHC.Conc.Signal 0.0 1.7
CAF GHC.IO.Handle.FD <entire-module> 0.0 88.2
CAF GHC.IO.Encoding <entire-module> 0.0 7.1
CAF GHC.Conc.Signal <entire-module> 0.0 1.7
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
individual inherited
COST CENTRE MODULE SRC no. entries %time %alloc %time %alloc
MAIN MAIN 105 0 0.0 0.9 0.0 100.0
CAF Main 209 0 0.0 0.9 0.0 1.5
g Main 212 1 0.0 0.1 0.0 0.1
f Main 211 1 0.0 0.1 0.0 0.1
main Main 210 1 0.0 0.2 0.0 0.4
f Main 214 0 0.0 0.0 0.0 0.2
g Main 215 0 0.0 0.0 0.0 0.2
h Main 216 1 0.0 0.2 0.0 0.2
CAF GHC.Conc.Signal 203 0 0.0 1.7 0.0 1.7
CAF GHC.IO.Encoding 193 0 0.0 7.3 0.0 7.3
CAF GHC.IO.Encoding.Iconv 191 0 0.0 0.6 0.0 0.6
CAF GHC.IO.Handle.FD 183 0 0.0 88.0 0.0 88.0
MAIN MAIN <built-in> 43 0 0.0 0.9 0.0 100.0
CAF Main <entire-module> 85 0 0.0 0.9 0.0 1.5
f Main T5654b-O0.hs:12:1-7 87 1 0.0 0.1 0.0 0.1
g Main T5654b-O0.hs:16:1-7 88 1 0.0 0.1 0.0 0.1
main Main T5654b-O0.hs:22:1-21 86 1 0.0 0.2 0.0 0.4
f Main T5654b-O0.hs:12:1-7 90 0 0.0 0.0 0.0 0.2
g Main T5654b-O0.hs:16:1-7 91 0 0.0 0.0 0.0 0.2
h Main T5654b-O0.hs:20:1-19 92 1 0.0 0.2 0.0 0.2
CAF GHC.Conc.Signal <entire-module> 77 0 0.0 1.7 0.0 1.7
CAF GHC.IO.Encoding <entire-module> 74 0 0.0 7.1 0.0 7.1
CAF GHC.IO.Handle.FD <entire-module> 72 0 0.0 88.2 0.0 88.2
CAF GHC.IO.Encoding.Iconv <entire-module> 54 0 0.0 0.6 0.0 0.6
Wed Jan 27 08:16 2016 Time and Allocation Profiling Report (Final)
Fri Jun 3 11:00 2016 Time and Allocation Profiling Report (Final)
T5654b-O1 +RTS -p -RTS
T5654b-O1 +RTS -hc -p -RTS
total time = 0.00 secs (0 ticks @ 1000 us, 1 processor)
total alloc = 39,016 bytes (excludes profiling overheads)
total alloc = 38,880 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
COST CENTRE MODULE SRC %time %alloc
MAIN MAIN 0.0 1.7
CAF GHC.IO.Handle.FD 0.0 88.5
CAF GHC.IO.Encoding 0.0 7.4
CAF GHC.Conc.Signal 0.0 1.7
MAIN MAIN <built-in> 0.0 1.7
CAF GHC.IO.Handle.FD <entire-module> 0.0 88.8
CAF GHC.IO.Encoding <entire-module> 0.0 7.1
CAF GHC.Conc.Signal <entire-module> 0.0 1.7
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
individual inherited
COST CENTRE MODULE SRC no. entries %time %alloc %time %alloc
MAIN MAIN 105 0 0.0 1.7 0.0 100.0
CAF Main 209 0 0.0 0.0 0.0 0.1
main Main 210 1 0.0 0.1 0.0 0.1
f Main 211 1 0.0 0.0 0.0 0.0
g Main 212 1 0.0 0.0 0.0 0.0
h Main 213 1 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal 203 0 0.0 1.7 0.0 1.7
CAF GHC.IO.Encoding 193 0 0.0 7.4 0.0 7.4
CAF GHC.IO.Encoding.Iconv 191 0 0.0 0.6 0.0 0.6
CAF GHC.IO.Handle.FD 183 0 0.0 88.5 0.0 88.5
MAIN MAIN <built-in> 43 0 0.0 1.7 0.0 100.0
CAF Main <entire-module> 85 0 0.0 0.0 0.0 0.1
main Main T5654b-O1.hs:22:1-21 86 1 0.0 0.1 0.0 0.1
f Main T5654b-O1.hs:12:1-7 87 1 0.0 0.0 0.0 0.0
g Main T5654b-O1.hs:16:1-7 88 1 0.0 0.0 0.0 0.0
h Main T5654b-O1.hs:20:1-19 89 1 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal <entire-module> 79 0 0.0 1.7 0.0 1.7
CAF GHC.IO.Encoding <entire-module> 74 0 0.0 7.1 0.0 7.1
CAF GHC.IO.Handle.FD <entire-module> 72 0 0.0 88.8 0.0 88.8
CAF GHC.IO.Encoding.Iconv <entire-module> 53 0 0.0 0.6 0.0 0.6
Thu Apr 2 19:44 2015 Time and Allocation Profiling Report (Final)
Sat Jun 4 11:59 2016 Time and Allocation Profiling Report (Final)
T680 +RTS -p -RTS
T680 +RTS -hc -p -RTS
total time = 0.20 secs (203 ticks @ 1000 us, 1 processor)
total alloc = 449,665,336 bytes (excludes profiling overheads)
total time = 0.00 secs (0 ticks @ 1000 us, 1 processor)
total alloc = 752,952 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc
COST CENTRE MODULE SRC %time %alloc
foo.\ Main 100.0 99.8
CAF GHC.IO.Handle.FD <entire-module> 0.0 4.6
main Main T680.hs:20:1-14 0.0 1.2
foo.\ Main T680.hs:3:12-40 0.0 25.5
foo.bar Main T680.hs:(5,3)-(9,38) 0.0 29.8
foo.bar.\ Main T680.hs:(8,11)-(9,38) 0.0 38.2
individual inherited
COST CENTRE MODULE no. entries %time %alloc %time %alloc
individual inherited
COST CENTRE MODULE SRC no. entries %time %alloc %time %alloc
MAIN MAIN 103 0 0.0 0.0 100.0 100.0
CAF Main 205 0 0.0 0.0 100.0 100.0
k Main 208 1 0.0 0.0 0.0 0.0
foo Main 209 1 0.0 0.0 0.0 0.0
foo.bar Main 213 1 0.0 0.0 0.0 0.0
foo.bar.k' Main 217 1 0.0 0.0 0.0 0.0
k.\ Main 218 1 0.0 0.0 0.0 0.0
r Main 207 1 0.0 0.0 100.0 100.0
k Main 210 0 0.0 0.0 100.0 100.0
foo Main 211 0 0.0 0.0 100.0 100.0
foo.bar Main 214 0 0.0 0.0 0.0 0.1
foo.bar.k' Main 219 0 0.0 0.0 0.0 0.0
foo.bar.\ Main 215 4001 0.0 0.1 0.0 0.1
foo.bar.\.k'' Main 216 4000 0.0 0.0 0.0 0.0
foo.\ Main 212 4001 100.0 99.8 100.0 99.8
main Main 206 1 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal 184 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding 167 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv 165 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.FD 156 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.Text 154 0 0.0 0.0 0.0 0.0
CAF GHC.Show 141 0 0.0 0.0 0.0 0.0
MAIN MAIN <built-in> 46 0 0.0 0.1 0.0 100.0
CAF Main <entire-module> 91 0 0.0 0.0 0.0 93.6
k Main T680.hs:12:1-17 95 1 0.0 0.0 0.0 0.0
foo Main T680.hs:(2,1)-(9,38) 96 1 0.0 0.0 0.0 0.0
foo.bar Main T680.hs:(5,3)-(9,38) 100 1 0.0 0.0 0.0 0.0
foo.bar.k' Main T680.hs:6:9-34 104 1 0.0 0.0 0.0 0.0
k.\ Main T680.hs:12:16 105 1 0.0 0.0 0.0 0.0
main Main T680.hs:20:1-14 92 1 0.0 0.0 0.0 0.0
r Main T680.hs:18:1-26 94 1 0.0 0.0 0.0 93.5
k Main T680.hs:12:1-17 97 0 0.0 0.0 0.0 93.5
foo Main T680.hs:(2,1)-(9,38) 98 0 0.0 0.0 0.0 93.5
foo.\ Main T680.hs:3:12-40 99 4001 0.0 25.5 0.0 25.5
foo.bar Main T680.hs:(5,3)-(9,38) 101 0 0.0 29.8 0.0 68.0
foo.bar.\ Main T680.hs:(8,11)-(9,38) 102 4001 0.0 38.2 0.0 38.2
foo.bar.\.k'' Main T680.hs:8:15-27 103 4000 0.0 0.0 0.0 0.0
foo.bar.k' Main T680.hs:6:9-34 106 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Handle.FD <entire-module> 84 0 0.0 4.6 0.0 4.6
CAF GHC.IO.Handle.Text <entire-module> 83 0 0.0 0.0 0.0 0.0
CAF GHC.Conc.Signal <entire-module> 80 0 0.0 0.1 0.0 0.1
CAF GHC.IO.Encoding <entire-module> 78 0 0.0 0.4 0.0 0.4
CAF GHC.Show <entire-module> 76 0 0.0 0.0 0.0 0.0
CAF GHC.IO.Encoding.Iconv <entire-module> 62 0 0.0 0.0 0.0 0.0
main Main T680.hs:20:1-14 93 0 0.0 1.2 0.0 1.2
......@@ -39,7 +39,7 @@ test('T3001-2', [only_ways(['prof_hb']), extra_ways(['prof_hb'])],
# As with ioprof001, the unoptimised profile is different but
# not badly wrong (CAF attribution is different).
test('scc001', [expect_broken_for_10037], compile_and_run,
test('scc001', [], compile_and_run,
['-fno-state-hack -fno-full-laziness']) # Note [consistent stacks]
test('scc002', [], compile_and_run, [''])
......
Fri Oct 30 17:14 2015 Time and Allocation Profiling Report (Final)
Sat Jun 4 11:59 2016 Time and Allocation Profiling Report (Final)
ioprof +RTS -hc -p -RTS
total time = 0.00 secs (0 ticks @ 1000 us, 1 processor)
total alloc = 63,680 bytes (excludes profiling overheads)
total alloc = 180,024 bytes (excludes profiling overheads)
COST CENTRE MODULE %time %alloc