1 /* 2 * Copyright (c) 1997, 2013, Oracle and/or its affiliates. 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 Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA 20 * or visit www.oracle.com if you need additional information or have any 21 * questions. 22 * 23 */ 24 25 #include "precompiled.hpp" 26 #include "code/nmethod.hpp" 27 #include "compiler/compileBroker.hpp" 28 #include "opto/compile.hpp" 29 #include "opto/matcher.hpp" 30 #include "opto/node.hpp" 31 #include "opto/phase.hpp" 32 33 #ifndef PRODUCT 34 int Phase::_total_bytes_compiled = 0; 35 36 elapsedTimer Phase::_t_totalCompilation; 37 elapsedTimer Phase::_t_methodCompilation; 38 elapsedTimer Phase::_t_stubCompilation; 39 #endif 40 41 // The next timers used for LogCompilation 42 elapsedTimer Phase::_t_parser; 43 elapsedTimer Phase::_t_optimizer; 44 elapsedTimer Phase::_t_escapeAnalysis; 45 elapsedTimer Phase::_t_connectionGraph; 46 elapsedTimer Phase::_t_idealLoop; 47 elapsedTimer Phase::_t_ccp; 48 elapsedTimer Phase::_t_matcher; 49 elapsedTimer Phase::_t_registerAllocation; 50 elapsedTimer Phase::_t_output; 51 52 #ifndef PRODUCT 53 elapsedTimer Phase::_t_graphReshaping; 54 elapsedTimer Phase::_t_scheduler; 55 elapsedTimer Phase::_t_blockOrdering; 56 elapsedTimer Phase::_t_macroEliminate; 57 elapsedTimer Phase::_t_macroExpand; 58 elapsedTimer Phase::_t_peephole; 59 elapsedTimer Phase::_t_postalloc_expand; 60 elapsedTimer Phase::_t_codeGeneration; 61 elapsedTimer Phase::_t_registerMethod; 62 elapsedTimer Phase::_t_temporaryTimer1; 63 elapsedTimer Phase::_t_temporaryTimer2; 64 elapsedTimer Phase::_t_idealLoopVerify; 65 66 // Subtimers for _t_optimizer 67 elapsedTimer Phase::_t_iterGVN; 68 elapsedTimer Phase::_t_iterGVN2; 69 elapsedTimer Phase::_t_incrInline; 70 elapsedTimer Phase::_t_renumberLive; 71 72 73 // Subtimers for _t_registerAllocation 74 elapsedTimer Phase::_t_ctorChaitin; 75 elapsedTimer Phase::_t_buildIFGphysical; 76 elapsedTimer Phase::_t_computeLive; 77 elapsedTimer Phase::_t_regAllocSplit; 78 elapsedTimer Phase::_t_postAllocCopyRemoval; 79 elapsedTimer Phase::_t_mergeMultidefs; 80 elapsedTimer Phase::_t_fixupSpills; 81 82 // Subtimers for _t_output 83 elapsedTimer Phase::_t_instrSched; 84 elapsedTimer Phase::_t_buildOopMaps; 85 #endif 86 87 //------------------------------Phase------------------------------------------ 88 Phase::Phase( PhaseNumber pnum ) : _pnum(pnum), C( pnum == Compiler ? NULL : Compile::current()) { 89 // Poll for requests from shutdown mechanism to quiesce compiler (4448539, 4448544). 90 // This is an effective place to poll, since the compiler is full of phases. 91 // In particular, every inlining site uses a recursively created Parse phase. 92 CompileBroker::maybe_block(); 93 } 94 95 #ifndef PRODUCT 96 static const double minimum_reported_time = 0.0001; // seconds 97 static const double expected_method_compile_coverage = 0.97; // % 98 static const double minimum_meaningful_method_compile = 2.00; // seconds 99 100 void Phase::print_timers() { 101 tty->print_cr ("Accumulated compiler times:"); 102 tty->print_cr ("---------------------------"); 103 tty->print_cr (" Total compilation: %3.3f sec.", Phase::_t_totalCompilation.seconds()); 104 tty->print (" method compilation : %3.3f sec", Phase::_t_methodCompilation.seconds()); 105 tty->print ("/%d bytes",_total_bytes_compiled); 106 tty->print_cr (" (%3.0f bytes per sec) ", Phase::_total_bytes_compiled / Phase::_t_methodCompilation.seconds()); 107 tty->print_cr (" stub compilation : %3.3f sec.", Phase::_t_stubCompilation.seconds()); 108 tty->print_cr (" Phases:"); 109 tty->print_cr (" parse : %3.3f sec", Phase::_t_parser.seconds()); 110 tty->print_cr (" optimizer : %3.3f sec", Phase::_t_optimizer.seconds()); 111 if( Verbose || WizardMode ) { 112 if (DoEscapeAnalysis) { 113 // EA is part of Optimizer. 114 tty->print_cr (" escape analysis: %3.3f sec", Phase::_t_escapeAnalysis.seconds()); 115 tty->print_cr (" connection graph: %3.3f sec", Phase::_t_connectionGraph.seconds()); 116 tty->print_cr (" macroEliminate : %3.3f sec", Phase::_t_macroEliminate.seconds()); 117 } 118 tty->print_cr (" iterGVN : %3.3f sec", Phase::_t_iterGVN.seconds()); 119 tty->print_cr (" incrInline : %3.3f sec", Phase::_t_incrInline.seconds()); 120 tty->print_cr (" renumberLive : %3.3f sec", Phase::_t_renumberLive.seconds()); 121 tty->print_cr (" idealLoop : %3.3f sec", Phase::_t_idealLoop.seconds()); 122 tty->print_cr (" idealLoopVerify: %3.3f sec", Phase::_t_idealLoopVerify.seconds()); 123 tty->print_cr (" ccp : %3.3f sec", Phase::_t_ccp.seconds()); 124 tty->print_cr (" iterGVN2 : %3.3f sec", Phase::_t_iterGVN2.seconds()); 125 tty->print_cr (" macroExpand : %3.3f sec", Phase::_t_macroExpand.seconds()); 126 tty->print_cr (" graphReshape : %3.3f sec", Phase::_t_graphReshaping.seconds()); 127 double optimizer_subtotal = Phase::_t_iterGVN.seconds() + Phase::_t_iterGVN2.seconds() + Phase::_t_renumberLive.seconds() + 128 Phase::_t_escapeAnalysis.seconds() + Phase::_t_macroEliminate.seconds() + 129 Phase::_t_idealLoop.seconds() + Phase::_t_ccp.seconds() + 130 Phase::_t_macroExpand.seconds() + Phase::_t_graphReshaping.seconds(); 131 double percent_of_optimizer = ((optimizer_subtotal == 0.0) ? 0.0 : (optimizer_subtotal / Phase::_t_optimizer.seconds() * 100.0)); 132 tty->print_cr (" subtotal : %3.3f sec, %3.2f %%", optimizer_subtotal, percent_of_optimizer); 133 } 134 tty->print_cr (" matcher : %3.3f sec", Phase::_t_matcher.seconds()); 135 tty->print_cr (" scheduler : %3.3f sec", Phase::_t_scheduler.seconds()); 136 tty->print_cr (" regalloc : %3.3f sec", Phase::_t_registerAllocation.seconds()); 137 if( Verbose || WizardMode ) { 138 tty->print_cr (" ctorChaitin : %3.3f sec", Phase::_t_ctorChaitin.seconds()); 139 tty->print_cr (" buildIFG : %3.3f sec", Phase::_t_buildIFGphysical.seconds()); 140 tty->print_cr (" computeLive : %3.3f sec", Phase::_t_computeLive.seconds()); 141 tty->print_cr (" regAllocSplit : %3.3f sec", Phase::_t_regAllocSplit.seconds()); 142 tty->print_cr (" postAllocCopyRemoval: %3.3f sec", Phase::_t_postAllocCopyRemoval.seconds()); 143 tty->print_cr (" mergeMultidefs: %3.3f sec", Phase::_t_mergeMultidefs.seconds()); 144 tty->print_cr (" fixupSpills : %3.3f sec", Phase::_t_fixupSpills.seconds()); 145 double regalloc_subtotal = Phase::_t_ctorChaitin.seconds() + 146 Phase::_t_buildIFGphysical.seconds() + Phase::_t_computeLive.seconds() + 147 Phase::_t_regAllocSplit.seconds() + Phase::_t_fixupSpills.seconds() + 148 Phase::_t_postAllocCopyRemoval.seconds() + Phase::_t_mergeMultidefs.seconds(); 149 double percent_of_regalloc = ((regalloc_subtotal == 0.0) ? 0.0 : (regalloc_subtotal / Phase::_t_registerAllocation.seconds() * 100.0)); 150 tty->print_cr (" subtotal : %3.3f sec, %3.2f %%", regalloc_subtotal, percent_of_regalloc); 151 } 152 tty->print_cr (" blockOrdering : %3.3f sec", Phase::_t_blockOrdering.seconds()); 153 tty->print_cr (" peephole : %3.3f sec", Phase::_t_peephole.seconds()); 154 if (Matcher::require_postalloc_expand) { 155 tty->print_cr (" postalloc_expand: %3.3f sec", Phase::_t_postalloc_expand.seconds()); 156 } 157 tty->print_cr (" codeGen : %3.3f sec", Phase::_t_codeGeneration.seconds()); 158 tty->print_cr (" install_code : %3.3f sec", Phase::_t_registerMethod.seconds()); 159 tty->print_cr (" -------------- : ----------"); 160 double phase_subtotal = Phase::_t_parser.seconds() + 161 Phase::_t_optimizer.seconds() + Phase::_t_graphReshaping.seconds() + 162 Phase::_t_matcher.seconds() + Phase::_t_scheduler.seconds() + 163 Phase::_t_registerAllocation.seconds() + Phase::_t_blockOrdering.seconds() + 164 Phase::_t_codeGeneration.seconds() + Phase::_t_registerMethod.seconds(); 165 double percent_of_method_compile = ((phase_subtotal == 0.0) ? 0.0 : phase_subtotal / Phase::_t_methodCompilation.seconds()) * 100.0; 166 // counters inside Compile::CodeGen include time for adapters and stubs 167 // so phase-total can be greater than 100% 168 tty->print_cr (" total : %3.3f sec, %3.2f %%", phase_subtotal, percent_of_method_compile); 169 170 assert( percent_of_method_compile > expected_method_compile_coverage || 171 phase_subtotal < minimum_meaningful_method_compile, 172 "Must account for method compilation"); 173 174 if( Phase::_t_temporaryTimer1.seconds() > minimum_reported_time ) { 175 tty->cr(); 176 tty->print_cr (" temporaryTimer1: %3.3f sec", Phase::_t_temporaryTimer1.seconds()); 177 } 178 if( Phase::_t_temporaryTimer2.seconds() > minimum_reported_time ) { 179 tty->cr(); 180 tty->print_cr (" temporaryTimer2: %3.3f sec", Phase::_t_temporaryTimer2.seconds()); 181 } 182 tty->print_cr (" output : %3.3f sec", Phase::_t_output.seconds()); 183 tty->print_cr (" isched : %3.3f sec", Phase::_t_instrSched.seconds()); 184 tty->print_cr (" bldOopMaps : %3.3f sec", Phase::_t_buildOopMaps.seconds()); 185 } 186 #endif