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