1/* 2 * Copyright (c) 2022 Huawei Device Co., Ltd. 3 * Licensed under the Apache License, Version 2.0 (the "License"); 4 * you may not use this file except in compliance with the License. 5 * You may obtain a copy of the License at 6 * 7 * http://www.apache.org/licenses/LICENSE-2.0 8 * 9 * Unless required by applicable law or agreed to in writing, software 10 * distributed under the License is distributed on an "AS IS" BASIS, 11 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 12 * See the License for the specific language governing permissions and 13 * limitations under the License. 14 */ 15 16#include "ecmascript/compiler/compiler_log.h" 17 18namespace panda::ecmascript::kungfu { 19CompilerLog::CompilerLog(const std::string &logOpt) 20{ 21 outputCIR_ = (logOpt.find("cir") != std::string::npos) || (logOpt.find("0") != std::string::npos); 22 outputLLIR_ = (logOpt.find("llir") != std::string::npos) || (logOpt.find("1") != std::string::npos); 23 outputASM_ = (logOpt.find("asm") != std::string::npos) || (logOpt.find("2") != std::string::npos); 24 outputType_ = (logOpt.find("type") != std::string::npos) || (logOpt.find("3") != std::string::npos); 25 allMethod_ = logOpt.find("all") != std::string::npos; 26 cerMethod_ = (logOpt.find("all") == std::string::npos) && (logOpt.find("cer") != std::string::npos); 27 noneMethod_ = (logOpt.find("all") == std::string::npos) && (logOpt.find("cer") == std::string::npos); 28} 29 30void CompilerLog::SetMethodLog(const std::string &fileName, 31 const std::string &methodName, AotMethodLogList *logList) 32{ 33 bool enableMethodLog = !NoneMethod(); 34 if (CertainMethod()) { 35 enableMethodLog = logList->IncludesMethod(fileName, methodName); 36 } 37 SetEnableMethodLog(enableMethodLog); 38} 39 40void CompilerLog::SetStubLog(const std::string &stubName, MethodLogList *logList) 41{ 42 bool enableMethodLog = !NoneMethod(); 43 if (CertainMethod()) { 44 enableMethodLog = logList->IncludesMethod(stubName); 45 } 46 SetEnableMethodLog(enableMethodLog); 47} 48 49bool MethodLogList::IncludesMethod(const std::string &methodName) const 50{ 51 bool empty = methodName.empty(); 52 bool found = methods_.find(methodName) != std::string::npos; 53 return !empty && found; 54} 55 56bool AotMethodLogList::IncludesMethod(const std::string &fileName, const std::string &methodName) const 57{ 58 if (fileMethods_.find(fileName) == fileMethods_.end()) { 59 return false; 60 } 61 std::vector methodVector = fileMethods_.at(fileName); 62 auto it = find(methodVector.begin(), methodVector.end(), methodName); 63 return (it != methodVector.end()); 64} 65 66std::vector<std::string> AotMethodLogList::spiltString(const std::string &str, const char ch) 67{ 68 std::vector<std::string> vec {}; 69 std::istringstream sstr(str.c_str()); 70 std::string spilt; 71 while (getline(sstr, spilt, ch)) { 72 vec.emplace_back(spilt); 73 } 74 return vec; 75} 76 77void AotMethodLogList::ParseFileMethodsName(const std::string &logMethods) 78{ 79 std::vector<std::string> fileVector = spiltString(logMethods, fileSplitSign); 80 std::vector<std::string> itemVector; 81 for (size_t index = 0; index < fileVector.size(); ++index) { 82 itemVector = spiltString(fileVector[index], methodSplitSign); 83 std::vector<std::string> methodVector(itemVector.begin() + 1, itemVector.end()); 84 fileMethods_[itemVector[0]] = methodVector; 85 } 86} 87 88TimeScope::TimeScope(std::string name, std::string methodName, uint32_t methodOffset, CompilerLog* log) 89 : ClockScope(), name_(std::move(name)), methodName_(std::move(methodName)), methodOffset_(methodOffset), log_(log) 90{ 91 if (log_->GetEnableCompilerLogTime()) { 92 if (log_->nameIndex_.find(name_) == log_->nameIndex_.end()) { 93 log_->nameIndex_[name_] = log_->GetIndex(); 94 } 95 startTime_ = ClockScope().GetCurTime(); 96 } 97} 98 99TimeScope::TimeScope(std::string name, CompilerLog* log) 100 : ClockScope(), name_(std::move(name)), log_(log) 101{ 102 if (log_->GetEnableCompilerLogTime()) { 103 if (log_->nameIndex_.find(name_) == log_->nameIndex_.end()) { 104 log_->nameIndex_[name_] = log_->GetIndex(); 105 } 106 startTime_ = ClockScope().GetCurTime(); 107 } 108} 109 110TimeScope::~TimeScope() 111{ 112 if (log_->GetEnableCompilerLogTime()) { 113 timeUsed_ = ClockScope().GetCurTime() - startTime_; 114 if (log_->CertainMethod() && log_->GetEnableMethodLog()) { 115 LOG_COMPILER(INFO) << std::setw(PASS_LENS) << name_ << " " << std::setw(METHOD_LENS) 116 << GetShortName(methodName_) << " offset:" << std::setw(OFFSET_LENS) << methodOffset_ 117 << " time used:" << std::setw(TIME_LENS) << timeUsed_ / MILLION_TIME << "ms"; 118 } 119 std::string shortName = GetShortName(methodName_); 120 log_->AddPassTime(name_, timeUsed_); 121 log_->AddMethodTime(shortName, methodOffset_, timeUsed_); 122 } 123} 124 125const std::string TimeScope::GetShortName(const std::string& methodName) 126{ 127 std::string KeyStr = "@"; 128 if (methodName.find(KeyStr) != std::string::npos) { 129 std::string::size_type index = methodName.find(KeyStr); 130 std::string extracted = methodName.substr(0, index); 131 return extracted; 132 } else { 133 return methodName; 134 } 135} 136 137void CompilerLog::Print() const 138{ 139 if (compilerLogTime_) { 140 PrintTime(); 141 } 142 PrintPGOMismatchedMethod(); 143 PrintCompiledMethod(); 144} 145 146void CompilerLog::PrintPassTime() const 147{ 148 double allPassTimeforAllMethods = 0; 149 auto myMap = timePassMap_; 150 auto myIndexMap = nameIndex_; 151 std::multimap<int, std::string> PassTimeMap; 152 for (auto it = myMap.begin(); it != myMap.end(); it++) { 153 PassTimeMap.insert(make_pair(myIndexMap[it->first], it->first)); 154 allPassTimeforAllMethods += it->second; 155 } 156 for (auto [key, val] : PassTimeMap) { 157 LOG_COMPILER(INFO) << std::setw(PASS_LENS) << val << " Total cost time is "<< std::setw(TIME_LENS) 158 << myMap[val] / MILLION_TIME << "ms " << "percentage:" 159 << std::fixed << std::setprecision(PERCENT_LENS) 160 << myMap[val] / allPassTimeforAllMethods * HUNDRED_TIME << "% "; 161 } 162} 163 164void CompilerLog::PrintMethodTime() const 165{ 166 double methodTotalTime = 0; 167 auto myMap = timeMethodMap_; 168 std::multimap<double, std::pair<uint32_t, std::string>> MethodTimeMap; 169 std::map<std::pair<uint32_t, std::string>, double>::iterator it; 170 for (it = myMap.begin(); it != myMap.end(); it++) { 171 MethodTimeMap.insert(make_pair(it->second, it->first)); 172 } 173 for (auto [key, val] : MethodTimeMap) { 174 methodTotalTime += key; 175 } 176 for (auto [key, val] : MethodTimeMap) { 177 LOG_COMPILER(INFO) << "method:" << std::setw(METHOD_LENS) << val.second 178 << " offset:" << std::setw(OFFSET_LENS) << val.first << " all pass cost time is " 179 << std::setw(TIME_LENS) << key / MILLION_TIME << "ms " << "percentage:" << std::fixed 180 << std::setprecision(PERCENT_LENS) << key / methodTotalTime * HUNDRED_TIME << "% "; 181 } 182 LOG_COMPILER(INFO) << "total compile time is " << std::setw(TIME_LENS) << methodTotalTime / MILLION_TIME << "ms "; 183} 184 185void CompilerLog::PrintTime() const 186{ 187 LOG_COMPILER(INFO) << " "; 188 PrintPassTime(); 189 LOG_COMPILER(INFO) << " "; 190 PrintMethodTime(); 191} 192 193void CompilerLog::PrintCompiledMethod() const 194{ 195 LOG_COMPILER(INFO) << " "; 196 LOG_COMPILER(INFO) << " Total number of full compiled methods is: " << compiledMethodSet_.size(); 197 for (auto it = compiledMethodSet_.begin(); it != compiledMethodSet_.end(); it++) { 198 LOG_COMPILER(INFO) << " method: " << std::setw(METHOD_LENS) << it->first 199 << " in record: " << std::setw(RECORD_LENS) << it->second 200 << " has been full compiled "; 201 } 202} 203 204void CompilerLog::PrintPGOMismatchedMethod() const 205{ 206 if (totalPGOMethodCount_ == 0) { 207 return; 208 } 209 LOG_COMPILER(INFO) << " "; 210 LOG_COMPILER(INFO) << " Number of mismatched methods from ap file : " << mismatchPGOMethodCount_ << " / " 211 << totalPGOMethodCount_; 212 for (const auto &it : mismatchPGOMethodSet_) { 213 LOG_COMPILER(INFO) << " method: " << std::setw(METHOD_LENS) << it.first 214 << " in record: " << std::setw(RECORD_LENS) << it.second 215 << " has not been found in abc, and will be abandoned."; 216 } 217} 218 219void CompilerLog::AddMethodTime(const std::string& name, uint32_t id, double time) 220{ 221 auto methodInfo = std::make_pair(id, name); 222 timeMethodMap_[methodInfo] += time; 223} 224 225void CompilerLog::AddPassTime(const std::string& name, double time) 226{ 227 timePassMap_[name] += time; 228} 229 230void CompilerLog::AddCompiledMethod(const std::string& name, const CString& recordName) 231{ 232 auto info = std::make_pair(name, recordName); 233 compiledMethodSet_.insert(info); 234} 235 236void CompilerLog::RemoveCompiledMethod(const std::string& name, const CString& recordName) 237{ 238 auto info = std::make_pair(name, recordName); 239 compiledMethodSet_.erase(info); 240} 241 242int CompilerLog::GetIndex() 243{ 244 return (idx_++); 245} 246 247void PGOTypeLogList::CollectGateTypeLogInfo(GateRef gate, bool isBinOp) 248{ 249 log_ += "[PGOTypePrinter] "; 250 log_ += "gate id: "+ std::to_string(acc_.GetId(gate)) + ", "; 251 EcmaOpcode ecmaOpcode = acc_.GetByteCodeOpcode(gate); 252 log_ += "bytecode: " + GetEcmaOpcodeStr(ecmaOpcode); 253 254 uint32_t pcOffset = acc_.TryGetPcOffset(gate); 255 if (isBinOp) { 256 const PGOSampleType *sampleType = acc_.TryGetPGOType(gate).GetPGOSampleType(); 257 if (sampleType->IsString()) { 258 log_ += " [left type: string, right type: string]"; 259 } else if (sampleType->HasNumber()) { 260 if (sampleType->IsInt()) { 261 log_ += " [left type: int, right type: int]"; 262 } else { 263 if (sampleType->IsIntOverFlow()) { 264 log_ += " [left type: int, right type: int]"; 265 } else if (sampleType->IsDouble()) { 266 log_ += " [left type: double, right type: double]"; 267 } else { 268 log_ += " [left type: number, right type: number]"; 269 } 270 } 271 } else { 272 GateRef left = acc_.GetValueIn(gate, 0); 273 GateRef right = acc_.GetValueIn(gate, 1); 274 GateType leftType = acc_.GetGateType(left); 275 GateType rightType = acc_.GetGateType(right); 276 if (leftType.IsIntType()) { 277 log_ += " [left type: int, "; 278 } else if (leftType.IsDoubleType()) { 279 log_ += " [left type: double, "; 280 } else { 281 log_ += " [left type: number, "; 282 } 283 if (rightType.IsIntType()) { 284 log_ += "right type: int]"; 285 } else if (rightType.IsDoubleType()) { 286 log_ += "right type: double]"; 287 } else { 288 log_ += "right type: number]"; 289 } 290 } 291 } else { 292 GateRef value = acc_.GetValueIn(gate, 0); 293 GateType valueType = acc_.GetGateType(value); 294 if (valueType.IsIntType()) { 295 log_ += " [type: int]"; 296 } else if (valueType.IsDoubleType()) { 297 log_ += " [type: double]"; 298 } else { 299 log_ += " [type: number]"; 300 } 301 } 302 log_ += ", pcOffset: " + std::to_string(pcOffset); 303 log_ += "\n[compiler] "; 304} 305 306void PGOTypeLogList::PrintPGOTypeLog() 307{ 308 LOG_COMPILER(INFO) << log_; 309} 310 311void CompilerLog::SetPGOMismatchResult(uint32_t &totalMethodCount, uint32_t &mismatchMethodCount, 312 std::set<std::pair<std::string, CString>> &mismatchMethodSet) 313{ 314 totalPGOMethodCount_ = totalMethodCount; 315 mismatchPGOMethodCount_ = mismatchMethodCount; 316 mismatchPGOMethodSet_ = std::move(mismatchMethodSet); 317} 318 319} // namespace panda::ecmascript::kungfu 320