1 /*
2 * Copyright (c) 2024 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/module/module_logger.h"
17
18 #include "ecmascript/ecma_context.h"
19 #include "ecmascript/module/module_path_helper.h"
20 #include "ecmascript/runtime_lock.h"
21
22 #include <fstream>
23
24 namespace panda::ecmascript {
25
ModuleLogger(EcmaVM * vm)26 ModuleLogger::ModuleLogger(EcmaVM *vm) : vm_(vm) {}
27
PrintModuleLoadInfo()28 void ModuleLogger::PrintModuleLoadInfo()
29 {
30 ProcessModuleExecuteTime();
31 PrintSummary();
32 PrintUsedFileInfo();
33 PrintUnusedFileInfo();
34 }
35
CreateResultFile(std::string & path) const36 bool ModuleLogger::CreateResultFile(std::string &path) const
37 {
38 path = FILEDIR + std::string(vm_->GetBundleName().c_str()) + SUFFIX;
39 const mode_t defaultMode = S_IRUSR | S_IWUSR | S_IRGRP; // -rw-r--
40 int fd = creat(path.c_str(), defaultMode);
41 if (fd == -1) {
42 LOG_ECMA(ERROR) << "file create failed, errno = "<< errno;
43 return false;
44 }
45 close(fd);
46 return true;
47 }
48
OpenResultFile(std::string & path) const49 bool ModuleLogger::OpenResultFile(std::string &path) const
50 {
51 path = FILEDIR + std::string(vm_->GetBundleName().c_str()) + SUFFIX;
52 if (access(path.c_str(), F_OK) == 0) {
53 if (access(path.c_str(), W_OK) == 0) {
54 LOG_ECMA(DEBUG) << "file open success";
55 return true;
56 }
57 LOG_ECMA(ERROR) << "file create failed, W_OK false";
58 return false;
59 }
60 return CreateResultFile(path);
61 }
62
InsertModuleLoadInfo(JSHandle<SourceTextModule> currentModule,JSHandle<SourceTextModule> exportModule,int32_t index)63 void ModuleLogger::InsertModuleLoadInfo(JSHandle<SourceTextModule> currentModule,
64 JSHandle<SourceTextModule> exportModule, int32_t index)
65 {
66 JSThread *thread = vm_->GetJSThread();
67 RuntimeLockHolder locker(thread, mutex_);
68 CString curName = SourceTextModule::GetModuleName(currentModule.GetTaggedValue());
69 CString sonName = SourceTextModule::GetModuleName(exportModule.GetTaggedValue());
70 ModuleLoadInfo *sonModule = GetModuleLoadInfo(sonName);
71 sonModule->isUsed = true;
72 // get importName
73 CString exportNameStr;
74 if (index < 0) {
75 exportNameStr = "*";
76 } else {
77 JSHandle<TaggedArray> importArray(thread, currentModule->GetImportEntries());
78 JSHandle<ImportEntry> importEntry(thread, importArray->Get(index));
79 JSHandle<JSTaggedValue> importName(thread, importEntry->GetImportName());
80 exportNameStr = ModulePathHelper::Utf8ConvertToString(importName.GetTaggedValue());
81 }
82 auto &upLevelInfo = sonModule->upLevel;
83 auto ulModule = upLevelInfo.find(curName);
84 if (ulModule == upLevelInfo.end()) {
85 CSet<CString> tmp;
86 tmp.insert(exportNameStr);
87 upLevelInfo.emplace(curName, std::move(tmp));
88 return;
89 }
90 ulModule->second.insert(exportNameStr);
91 }
92
InsertParentModule(JSHandle<SourceTextModule> currentModule,JSHandle<SourceTextModule> requiredModule)93 void ModuleLogger::InsertParentModule(JSHandle<SourceTextModule> currentModule,
94 JSHandle<SourceTextModule> requiredModule)
95 {
96 RuntimeLockHolder locker(vm_->GetJSThread(), mutex_);
97 CString curName = currentModule->GetEcmaModuleRecordNameString();
98 CString sonName = requiredModule->GetEcmaModuleRecordNameString();
99 ModuleLoadInfo *sonModule = GetModuleLoadInfo(sonName);
100 sonModule->parentModules.insert(std::move(curName));
101 }
102
InsertEntryPointModule(JSHandle<SourceTextModule> currentModule)103 void ModuleLogger::InsertEntryPointModule(JSHandle<SourceTextModule> currentModule)
104 {
105 RuntimeLockHolder locker(vm_->GetJSThread(), mutex_);
106 CString curName = currentModule->GetEcmaModuleRecordNameString();
107 ModuleLoadInfo *curModule = GetModuleLoadInfo(curName);
108 curModule->isUsed = true;
109 auto &upLevelInfo = curModule->upLevel;
110 CSet<CString> tmp;
111 upLevelInfo.emplace("EntryPoint", tmp);
112 }
113
PrintSummary() const114 void ModuleLogger::PrintSummary() const
115 {
116 std::string path;
117 if (!CreateResultFile(path)) {
118 LOG_ECMA(ERROR) << "open file fail, no log anymore";
119 return;
120 }
121 std::ofstream fileHandle;
122 fileHandle.open(path, std::ios_base::app);
123 std::string start = "<----Summary----> Total file number: " + std::to_string(totalFileNumber_) + ", total time: " +
124 std::to_string(totalTime_) + "ms, including used file:" + std::to_string(usedFileNumber_) +
125 ", cost time: " + std::to_string(usedFileTime_) + "ms, and unused file: " +
126 std::to_string(unusedFileNumber_) +", cost time: " + std::to_string(unusedFileTime_) + "ms\n";
127 fileHandle << start;
128 fileHandle.close();
129 }
130
PrintUsedFileInfo() const131 void ModuleLogger::PrintUsedFileInfo() const
132 {
133 std::string path;
134 if (!OpenResultFile(path)) {
135 LOG_ECMA(ERROR) << "open file fail, no log anymore";
136 return;
137 }
138 std::ofstream fileHandle;
139 fileHandle.open(path, std::ios_base::app);
140 std::string start = "<----used file start----> used file: " + std::to_string(usedFileNumber_) + ", cost time: "
141 + std::to_string(usedFileTime_) + "ms\n";
142 fileHandle << start;
143 int32_t fileNumber = 1;
144 for (auto &i : jsModuleLoadInfo_) {
145 ModuleLoadInfo *info = i.second;
146 if (info->isUsed) {
147 std::string content = "used file " + std::to_string(fileNumber++) + ": " + i.first.c_str() +
148 ", cost time: " + ToStringWithPrecision(info->time, THREE) + "ms\n";
149 fileHandle << content;
150 auto &upInfo = info->upLevel;
151 int32_t parentModuleCount = 1;
152 for (auto &k : upInfo) {
153 std::string parentInfoStr = " parentModule " + std::to_string(parentModuleCount++) +
154 ": " + k.first.c_str() + " ";
155 for (auto &exportN : k.second) {
156 parentInfoStr += exportN + " ";
157 }
158 parentInfoStr += "\n";
159 fileHandle << parentInfoStr;
160 }
161 }
162 }
163 std::string end = "<----------used file end----------> \n";
164 fileHandle << end;
165 fileHandle.close();
166 }
167
PrintUnusedFileInfo() const168 void ModuleLogger::PrintUnusedFileInfo() const
169 {
170 std::string path;
171 if (!OpenResultFile(path)) {
172 LOG_ECMA(ERROR) << "open file fail, no log anymore";
173 return;
174 }
175 std::ofstream fileHandle;
176 fileHandle.open(path, std::ios_base::app);
177 std::string start = "<----unused file start----> unused file: " + std::to_string(unusedFileNumber_) +
178 ", cost time: " + std::to_string(unusedFileTime_) + "ms\n";
179 fileHandle << start;
180 int32_t fileNumber = 1;
181 for (auto &i : jsModuleLoadInfo_) {
182 ModuleLoadInfo *info = i.second;
183 if (!info->isUsed) {
184 std::string content = "unused file " + std::to_string(fileNumber++) + ": " + i.first.c_str() +
185 ", cost time: " + ToStringWithPrecision(info->time, THREE) + "ms\n";
186 fileHandle << content;
187 int32_t parentNumber = 1;
188 CSet<CString> parents = info->parentModules;
189 for (auto &k : parents) {
190 std::string parent = " parentModule " + std::to_string(parentNumber++) +
191 ": " + k.c_str() + "\n";
192 fileHandle << parent;
193 }
194 }
195 }
196 std::string end = "<----------unused file end----------> \n";
197 fileHandle << end;
198 fileHandle.close();
199 }
200
ProcessModuleExecuteTime()201 void ModuleLogger::ProcessModuleExecuteTime()
202 {
203 RuntimeLockHolder locker(vm_->GetJSThread(), mutex_);
204 totalFileNumber_ = jsModuleLoadInfo_.size();
205 double totalTime = 0;
206 double usedFileTime = 0;
207 double unusedFileTime = 0;
208 for (auto &i : jsModuleLoadInfo_) {
209 ModuleLoadInfo *info = i.second;
210 double time = info->time;
211 if (time > TWO_SECONDS) {
212 time = 0;
213 }
214 if (info->isUsed) {
215 usedFileNumber_++;
216 usedFileTime += time;
217 } else {
218 unusedFileNumber_++;
219 unusedFileTime += time;
220 }
221 totalTime += time;
222 }
223 totalTime_ = static_cast<int64_t>(totalTime);
224 usedFileTime_ = static_cast<int64_t>(usedFileTime);
225 unusedFileTime_ = static_cast<int64_t>(unusedFileTime);
226 }
227
GetModuleLoadInfo(const CString & recordName)228 ModuleLoadInfo *ModuleLogger::GetModuleLoadInfo(const CString &recordName)
229 {
230 auto info = jsModuleLoadInfo_.find(recordName);
231 if (info != jsModuleLoadInfo_.end()) {
232 return info->second;
233 }
234 ModuleLoadInfo *newInfo = new ModuleLoadInfo();
235 jsModuleLoadInfo_.emplace(recordName, newInfo);
236 return newInfo;
237 }
238
SetStartTime(const CString & recordName)239 void ModuleLogger::SetStartTime(const CString &recordName)
240 {
241 RuntimeLockHolder locker(vm_->GetJSThread(), mutex_);
242 ModuleLoadInfo *info = GetModuleLoadInfo(recordName);
243 info->time = std::chrono::duration_cast<std::chrono::microseconds>
244 (std::chrono::high_resolution_clock::now().time_since_epoch()).count();
245 }
246
SetEndTime(const CString & recordName)247 void ModuleLogger::SetEndTime(const CString &recordName)
248 {
249 RuntimeLockHolder locker(vm_->GetJSThread(), mutex_);
250 ModuleLoadInfo *info = GetModuleLoadInfo(recordName);
251 double time = info->time;
252 info->time = (std::chrono::duration_cast<std::chrono::microseconds>
253 (std::chrono::high_resolution_clock::now().time_since_epoch())
254 .count() - time) / DOUBLE_MILLISECONDS_PER_SEC;
255 }
256
ToStringWithPrecision(const double num,const uint8_t n)257 std::string ModuleLogger::ToStringWithPrecision(const double num, const uint8_t n)
258 {
259 std::ostringstream out;
260 out << std::setprecision(n) << num;
261 return out.str();
262 }
263
PostModuleLoggerTask(int32_t id,EcmaVM * vm)264 void ModuleLogger::PostModuleLoggerTask(int32_t id, EcmaVM *vm)
265 {
266 Taskpool::GetCurrentTaskpool()->PostTask(
267 std::make_unique<ModuleLoggerTask>(id, vm));
268 }
269
Run(uint32_t threadIndex)270 bool ModuleLogger::ModuleLoggerTask::Run([[maybe_unused]]uint32_t threadIndex)
271 {
272 ECMA_BYTRACE_NAME(HITRACE_TAG_ARK, "ModuleLoggerTask::Run");
273 std::this_thread::sleep_for(
274 std::chrono::microseconds(static_cast<int64_t>(TWO_SECONDS))); // 2s
275 ModuleLogger *moduleLogger =
276 vm_->GetJSThread()->GetCurrentEcmaContext()->GetModuleLogger();
277 moduleLogger->PrintModuleLoadInfo();
278 return true;
279 }
280 } // namespace panda::ecmascript
281