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
18 namespace panda::ecmascript::kungfu {
CompilerLog(const std::string & logOpt)19 CompilerLog::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
SetMethodLog(const std::string & fileName,const std::string & methodName,AotMethodLogList * logList)30 void 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
SetStubLog(const std::string & stubName,MethodLogList * logList)40 void 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
IncludesMethod(const std::string & methodName) const49 bool 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
IncludesMethod(const std::string & fileName,const std::string & methodName) const56 bool 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
spiltString(const std::string & str,const char ch)66 std::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
ParseFileMethodsName(const std::string & logMethods)77 void 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
TimeScope(std::string name,std::string methodName,uint32_t methodOffset,CompilerLog * log)88 TimeScope::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
TimeScope(std::string name,CompilerLog * log)99 TimeScope::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
~TimeScope()110 TimeScope::~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
GetShortName(const std::string & methodName)125 const 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
Print() const137 void CompilerLog::Print() const
138 {
139 if (compilerLogTime_) {
140 PrintTime();
141 }
142 PrintPGOMismatchedMethod();
143 PrintCompiledMethod();
144 }
145
PrintPassTime() const146 void 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
PrintMethodTime() const164 void 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
PrintTime() const185 void CompilerLog::PrintTime() const
186 {
187 LOG_COMPILER(INFO) << " ";
188 PrintPassTime();
189 LOG_COMPILER(INFO) << " ";
190 PrintMethodTime();
191 }
192
PrintCompiledMethod() const193 void 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
PrintPGOMismatchedMethod() const204 void 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
AddMethodTime(const std::string & name,uint32_t id,double time)219 void 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
AddPassTime(const std::string & name,double time)225 void CompilerLog::AddPassTime(const std::string& name, double time)
226 {
227 timePassMap_[name] += time;
228 }
229
AddCompiledMethod(const std::string & name,const CString & recordName)230 void CompilerLog::AddCompiledMethod(const std::string& name, const CString& recordName)
231 {
232 auto info = std::make_pair(name, recordName);
233 compiledMethodSet_.insert(info);
234 }
235
RemoveCompiledMethod(const std::string & name,const CString & recordName)236 void CompilerLog::RemoveCompiledMethod(const std::string& name, const CString& recordName)
237 {
238 auto info = std::make_pair(name, recordName);
239 compiledMethodSet_.erase(info);
240 }
241
GetIndex()242 int CompilerLog::GetIndex()
243 {
244 return (idx_++);
245 }
246
CollectGateTypeLogInfo(GateRef gate,bool isBinOp)247 void 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 PGOSampleType sampleType = acc_.TryGetPGOType(gate);
257 if (sampleType.IsNumber()) {
258 if (sampleType.IsInt()) {
259 log_ += " [left type: int, right type: int]";
260 } else {
261 if (sampleType.IsIntOverFlow()) {
262 log_ += " [left type: int, right type: int]";
263 } else if (sampleType.IsDouble()) {
264 log_ += " [left type: double, right type: double]";
265 } else {
266 log_ += " [left type: number, right type: number]";
267 }
268 }
269 } else {
270 GateRef left = acc_.GetValueIn(gate, 0);
271 GateRef right = acc_.GetValueIn(gate, 1);
272 GateType leftType = acc_.GetGateType(left);
273 GateType rightType = acc_.GetGateType(right);
274 if (leftType.IsIntType()) {
275 log_ += " [left type: int, ";
276 } else if (leftType.IsDoubleType()) {
277 log_ += " [left type: double, ";
278 } else {
279 log_ += " [left type: number, ";
280 }
281 if (rightType.IsIntType()) {
282 log_ += "right type: int]";
283 } else if (rightType.IsDoubleType()) {
284 log_ += "right type: double]";
285 } else {
286 log_ += "right type: number]";
287 }
288 }
289 } else {
290 GateRef value = acc_.GetValueIn(gate, 0);
291 GateType valueType = acc_.GetGateType(value);
292 if (valueType.IsIntType()) {
293 log_ += " [type: int]";
294 } else if (valueType.IsDoubleType()) {
295 log_ += " [type: double]";
296 } else {
297 log_ += " [type: number]";
298 }
299 }
300 log_ += ", pcOffset: " + std::to_string(pcOffset);
301 log_ += "\n[compiler] ";
302 }
303
PrintPGOTypeLog()304 void PGOTypeLogList::PrintPGOTypeLog()
305 {
306 LOG_COMPILER(INFO) << log_;
307 }
308
SetPGOMismatchResult(uint32_t & totalMethodCount,uint32_t & mismatchMethodCount,std::set<std::pair<std::string,CString>> & mismatchMethodSet)309 void CompilerLog::SetPGOMismatchResult(uint32_t &totalMethodCount, uint32_t &mismatchMethodCount,
310 std::set<std::pair<std::string, CString>> &mismatchMethodSet)
311 {
312 totalPGOMethodCount_ = totalMethodCount;
313 mismatchPGOMethodCount_ = mismatchMethodCount;
314 mismatchPGOMethodSet_ = std::move(mismatchMethodSet);
315 }
316
317 } // namespace panda::ecmascript::kungfu
318