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
24namespace panda::ecmascript {
25
26ModuleLogger::ModuleLogger(EcmaVM *vm) : vm_(vm) {}
27
28void ModuleLogger::PrintModuleLoadInfo()
29{
30    ProcessModuleExecuteTime();
31    PrintSummary();
32    PrintUsedFileInfo();
33    PrintUnusedFileInfo();
34}
35
36bool 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
49bool 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
63void 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
93void 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
103void 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
114void 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
131void 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
168void 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
201void 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
228ModuleLoadInfo *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
239void 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
247void 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
257std::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
264void ModuleLogger::PostModuleLoggerTask(int32_t id, EcmaVM *vm)
265{
266    Taskpool::GetCurrentTaskpool()->PostTask(
267        std::make_unique<ModuleLoggerTask>(id, vm));
268}
269
270bool 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