phase.cpp revision 605:98cb887364d3 
1/*
2 * Copyright 1997-2008 Sun Microsystems, Inc.  All Rights Reserved.
3 * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
4 *
5 * This code is free software; you can redistribute it and/or modify it
6 * under the terms of the GNU General Public License version 2 only, as
7 * published by the Free Software Foundation.
8 *
9 * This code is distributed in the hope that it will be useful, but WITHOUT
10 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
11 * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
12 * version 2 for more details (a copy is included in the LICENSE file that
13 * accompanied this code).
14 *
15 * You should have received a copy of the GNU General Public License version
16 * 2 along with this work; if not, write to the Free Software Foundation,
17 * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
18 *
19 * Please contact Sun Microsystems, Inc., 4150 Network Circle, Santa Clara,
20 * CA 95054 USA or visit www.sun.com if you need additional information or
21 * have any questions.
22 *
23 */
24
25#include "incls/_precompiled.incl"
26#include "incls/_phase.cpp.incl"
27
28#ifndef PRODUCT
29int Phase::_total_bytes_compiled = 0;
30
31elapsedTimer Phase::_t_totalCompilation;
32elapsedTimer Phase::_t_methodCompilation;
33elapsedTimer Phase::_t_stubCompilation;
34#endif
35
36// The next timers used for LogCompilation
37elapsedTimer Phase::_t_parser;
38elapsedTimer Phase::_t_escapeAnalysis;
39elapsedTimer Phase::_t_optimizer;
40elapsedTimer   Phase::_t_idealLoop;
41elapsedTimer   Phase::_t_ccp;
42elapsedTimer Phase::_t_matcher;
43elapsedTimer Phase::_t_registerAllocation;
44elapsedTimer Phase::_t_output;
45
46#ifndef PRODUCT
47elapsedTimer Phase::_t_graphReshaping;
48elapsedTimer Phase::_t_scheduler;
49elapsedTimer Phase::_t_blockOrdering;
50elapsedTimer Phase::_t_macroExpand;
51elapsedTimer Phase::_t_peephole;
52elapsedTimer Phase::_t_codeGeneration;
53elapsedTimer Phase::_t_registerMethod;
54elapsedTimer Phase::_t_temporaryTimer1;
55elapsedTimer Phase::_t_temporaryTimer2;
56
57// Subtimers for _t_optimizer
58elapsedTimer   Phase::_t_iterGVN;
59elapsedTimer   Phase::_t_iterGVN2;
60
61// Subtimers for _t_registerAllocation
62elapsedTimer   Phase::_t_ctorChaitin;
63elapsedTimer   Phase::_t_buildIFGphysical;
64elapsedTimer   Phase::_t_computeLive;
65elapsedTimer   Phase::_t_regAllocSplit;
66elapsedTimer   Phase::_t_postAllocCopyRemoval;
67elapsedTimer   Phase::_t_fixupSpills;
68
69// Subtimers for _t_output
70elapsedTimer   Phase::_t_instrSched;
71elapsedTimer   Phase::_t_buildOopMaps;
72#endif
73
74//------------------------------Phase------------------------------------------
75Phase::Phase( PhaseNumber pnum ) : _pnum(pnum), C( pnum == Compiler ? NULL : Compile::current()) {
76  // Poll for requests from shutdown mechanism to quiesce compiler (4448539, 4448544).
77  // This is an effective place to poll, since the compiler is full of phases.
78  // In particular, every inlining site uses a recursively created Parse phase.
79  CompileBroker::maybe_block();
80}
81
82#ifndef PRODUCT
83static const double minimum_reported_time             = 0.0001; // seconds
84static const double expected_method_compile_coverage  = 0.97;   // %
85static const double minimum_meaningful_method_compile = 2.00;   // seconds
86
87void Phase::print_timers() {
88  tty->print_cr ("Accumulated compiler times:");
89  tty->print_cr ("---------------------------");
90  tty->print_cr ("  Total compilation: %3.3f sec.", Phase::_t_totalCompilation.seconds());
91  tty->print    ("    method compilation : %3.3f sec", Phase::_t_methodCompilation.seconds());
92  tty->print    ("/%d bytes",_total_bytes_compiled);
93  tty->print_cr (" (%3.0f bytes per sec) ", Phase::_total_bytes_compiled / Phase::_t_methodCompilation.seconds());
94  tty->print_cr ("    stub compilation   : %3.3f sec.", Phase::_t_stubCompilation.seconds());
95  tty->print_cr ("  Phases:");
96  tty->print_cr ("    parse        : %3.3f sec", Phase::_t_parser.seconds());
97  if (DoEscapeAnalysis) {
98    tty->print_cr ("    escape analysis : %3.3f sec", Phase::_t_escapeAnalysis.seconds());
99  }
100  tty->print_cr ("    optimizer    : %3.3f sec", Phase::_t_optimizer.seconds());
101  if( Verbose || WizardMode ) {
102    tty->print_cr ("      iterGVN      : %3.3f sec", Phase::_t_iterGVN.seconds());
103    tty->print_cr ("      idealLoop    : %3.3f sec", Phase::_t_idealLoop.seconds());
104    tty->print_cr ("      ccp          : %3.3f sec", Phase::_t_ccp.seconds());
105    tty->print_cr ("      iterGVN2     : %3.3f sec", Phase::_t_iterGVN2.seconds());
106    tty->print_cr ("      graphReshape : %3.3f sec", Phase::_t_graphReshaping.seconds());
107    double optimizer_subtotal = Phase::_t_iterGVN.seconds() +
108      Phase::_t_idealLoop.seconds() + Phase::_t_ccp.seconds() +
109      Phase::_t_graphReshaping.seconds();
110    double percent_of_optimizer = ((optimizer_subtotal == 0.0) ? 0.0 : (optimizer_subtotal / Phase::_t_optimizer.seconds() * 100.0));
111    tty->print_cr ("      subtotal     : %3.3f sec,  %3.2f %%", optimizer_subtotal, percent_of_optimizer);
112  }
113  tty->print_cr ("    matcher      : %3.3f sec", Phase::_t_matcher.seconds());
114  tty->print_cr ("    scheduler    : %3.3f sec", Phase::_t_scheduler.seconds());
115  tty->print_cr ("    regalloc     : %3.3f sec", Phase::_t_registerAllocation.seconds());
116  if( Verbose || WizardMode ) {
117    tty->print_cr ("      ctorChaitin  : %3.3f sec", Phase::_t_ctorChaitin.seconds());
118    tty->print_cr ("      buildIFG     : %3.3f sec", Phase::_t_buildIFGphysical.seconds());
119    tty->print_cr ("      computeLive  : %3.3f sec", Phase::_t_computeLive.seconds());
120    tty->print_cr ("      regAllocSplit: %3.3f sec", Phase::_t_regAllocSplit.seconds());
121    tty->print_cr ("      postAllocCopyRemoval: %3.3f sec", Phase::_t_postAllocCopyRemoval.seconds());
122    tty->print_cr ("      fixupSpills  : %3.3f sec", Phase::_t_fixupSpills.seconds());
123    double regalloc_subtotal = Phase::_t_ctorChaitin.seconds() +
124      Phase::_t_buildIFGphysical.seconds() + Phase::_t_computeLive.seconds() +
125      Phase::_t_regAllocSplit.seconds()    + Phase::_t_fixupSpills.seconds() +
126      Phase::_t_postAllocCopyRemoval.seconds();
127    double percent_of_regalloc = ((regalloc_subtotal == 0.0) ? 0.0 : (regalloc_subtotal / Phase::_t_registerAllocation.seconds() * 100.0));
128    tty->print_cr ("      subtotal     : %3.3f sec,  %3.2f %%", regalloc_subtotal, percent_of_regalloc);
129  }
130  tty->print_cr ("    macroExpand  : %3.3f sec", Phase::_t_macroExpand.seconds());
131  tty->print_cr ("    blockOrdering: %3.3f sec", Phase::_t_blockOrdering.seconds());
132  tty->print_cr ("    peephole     : %3.3f sec", Phase::_t_peephole.seconds());
133  tty->print_cr ("    codeGen      : %3.3f sec", Phase::_t_codeGeneration.seconds());
134  tty->print_cr ("    install_code : %3.3f sec", Phase::_t_registerMethod.seconds());
135  tty->print_cr ("    ------------ : ----------");
136  double phase_subtotal = Phase::_t_parser.seconds() +
137    (DoEscapeAnalysis ? Phase::_t_escapeAnalysis.seconds() : 0.0) +
138    Phase::_t_optimizer.seconds() + Phase::_t_graphReshaping.seconds() +
139    Phase::_t_matcher.seconds() + Phase::_t_scheduler.seconds() +
140    Phase::_t_registerAllocation.seconds() + Phase::_t_blockOrdering.seconds() +
141    Phase::_t_macroExpand.seconds() + Phase::_t_peephole.seconds() +
142    Phase::_t_codeGeneration.seconds() + Phase::_t_registerMethod.seconds();
143  double percent_of_method_compile = ((phase_subtotal == 0.0) ? 0.0 : phase_subtotal / Phase::_t_methodCompilation.seconds()) * 100.0;
144  // counters inside Compile::CodeGen include time for adapters and stubs
145  // so phase-total can be greater than 100%
146  tty->print_cr ("    total        : %3.3f sec,  %3.2f %%", phase_subtotal, percent_of_method_compile);
147
148  assert( percent_of_method_compile > expected_method_compile_coverage ||
149          phase_subtotal < minimum_meaningful_method_compile,
150          "Must account for method compilation");
151
152  if( Phase::_t_temporaryTimer1.seconds() > minimum_reported_time ) {
153    tty->cr();
154    tty->print_cr ("    temporaryTimer1: %3.3f sec", Phase::_t_temporaryTimer1.seconds());
155  }
156  if( Phase::_t_temporaryTimer2.seconds() > minimum_reported_time ) {
157    tty->cr();
158    tty->print_cr ("    temporaryTimer2: %3.3f sec", Phase::_t_temporaryTimer2.seconds());
159  }
160  tty->print_cr ("    output    : %3.3f sec", Phase::_t_output.seconds());
161  tty->print_cr ("      isched    : %3.3f sec", Phase::_t_instrSched.seconds());
162  tty->print_cr ("      bldOopMaps: %3.3f sec", Phase::_t_buildOopMaps.seconds());
163}
164#endif
165