xref: /developtools/hiperf/src/debug_logger.cpp (revision 48f512ce) 
1/*
2 * Copyright (c) 2021-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 "debug_logger.h"
17
18#include <ratio>
19
20#include "option.h"
21#if defined(is_ohos) && is_ohos
22#include "hiperf_hilog.h"
23#endif
24
25using namespace std::literals::chrono_literals;
26using namespace std::chrono;
27namespace OHOS {
28namespace Developtools {
29namespace HiPerf {
30DebugLogger::DebugLogger() : timeStamp_(steady_clock::now()), logPath_(DEFAULT_LOG_PATH)
31{
32    OpenLog();
33}
34
35ScopeDebugLevel::ScopeDebugLevel(DebugLevel level, bool mix)
36{
37    savedDebugLevel_ = DebugLogger::GetInstance()->SetLogLevel(level);
38    savedMixOutput_ = DebugLogger::GetInstance()->SetMixLogOutput(mix);
39}
40
41ScopeDebugLevel::~ScopeDebugLevel()
42{
43    DebugLogger::GetInstance()->SetLogLevel(savedDebugLevel_);
44    DebugLogger::GetInstance()->SetMixLogOutput(savedMixOutput_);
45}
46
47DebugLogger::~DebugLogger()
48{
49    Disable();
50    if (file_ != nullptr) {
51        fclose(file_);
52        file_ = nullptr;
53    }
54}
55
56void DebugLogger::Disable(bool disable)
57{
58    if (logDisabled_ != disable) {
59        logDisabled_ = disable;
60        if (!disable) {
61            // reopen the log file
62            OpenLog();
63        }
64    }
65}
66
67#if is_ohos
68#ifndef CONFIG_NO_HILOG
69int DebugLogger::HiLog(std::string &buffer) const
70{
71    size_t lastLF = buffer.find_last_of('\n');
72    if (lastLF != std::string::npos) {
73        buffer.erase(lastLF, 1);
74    }
75    return OHOS::HiviewDFX::HiLog::Info(HIPERF_HILOG_LABLE[MODULE_DEFAULT], "%{public}s",
76                                        buffer.c_str());
77}
78#endif
79#endif
80
81int DebugLogger::Log(DebugLevel level, const std::string &logTag, const char *fmt, ...) const
82{
83    constexpr const int DEFAULT_STRING_BUF_SIZE = 4096;
84#ifdef HIPERF_DEBUG_TIME
85    const auto startSprintf = steady_clock::now();
86#endif
87    const auto startTime = steady_clock::now();
88    if (!ShouldLog(level, logTag) or logDisabled_ or fmt == nullptr) {
89#ifdef HIPERF_DEBUG_TIME
90        logTimes_ += duration_cast<microseconds>(steady_clock::now() - startSprintf);
91#endif
92        return 0;
93    }
94    va_list va;
95    int ret = 0;
96
97    std::string buffer(DEFAULT_STRING_BUF_SIZE, '\0');
98    va_start(va, fmt);
99    ret = vsnprintf_s(buffer.data(), buffer.size(), buffer.size() >= 1 ? buffer.size() - 1 : 0, fmt, va);
100    va_end(va);
101#ifdef HIPERF_DEBUG_TIME
102    logSprintfTimes_ += duration_cast<microseconds>(steady_clock::now() - startSprintf);
103#endif
104    if ((mixLogOutput_ and level < LEVEL_FATAL) or level == LEVEL_FATAL) {
105        ret = fprintf(stdout, "%s", buffer.data()); // to the stdout
106    }
107
108    if (enableHilog_) {
109#if is_ohos && !defined(CONFIG_NO_HILOG)
110        std::lock_guard<std::recursive_mutex> lock(logMutex_);
111        ret = HiLog(buffer); // to the hilog
112#endif
113    } else if (file_ != nullptr) {
114        std::lock_guard<std::recursive_mutex> lock(logMutex_);
115#ifdef HIPERF_DEBUG_TIME
116        const auto startWriteTime = steady_clock::now();
117#endif
118        milliseconds timeStamp = duration_cast<milliseconds>(startTime - timeStamp_);
119        fprintf(file_, "%05" PRId64 "ms %s", (int64_t)timeStamp.count(), buffer.data()); // to the file
120#ifdef HIPERF_DEBUG_TIME
121        logWriteTimes_ += duration_cast<microseconds>(steady_clock::now() - startWriteTime);
122#endif
123    }
124
125#ifdef HIPERF_DEBUG_TIME
126    logTimes_ += duration_cast<microseconds>(steady_clock::now() - startTime);
127    logCount_++;
128#endif
129    if (level == LEVEL_FATAL && exitOnFatal_) {
130        fflush(file_);
131        logDisabled_ = true;
132        exit(-1);
133    }
134    return ret;
135}
136
137bool DebugLogger::EnableHiLog(bool enable)
138{
139    enableHilog_ = enable;
140    if (enable) {
141        if (fprintf(stdout, "change to use hilog\n") < 0) {
142            // what can we do here ???
143        }
144    }
145    return enableHilog_;
146}
147
148bool DebugLogger::ShouldLog(DebugLevel level, const std::string &logtag) const
149{
150    return GetLogLevelByTag(logtag) <= level;
151}
152
153DebugLevel DebugLogger::SetLogLevel(DebugLevel debugLevel)
154{
155    DebugLevel lastLevel = DebugLogger::GetInstance()->debugLevel_;
156    debugLevel_ = debugLevel;
157    // force print
158    printf("setLogLevel %d\n", debugLevel);
159    return lastLevel;
160}
161
162bool DebugLogger::SetMixLogOutput(bool enable)
163{
164    bool lastMixLogOutput = mixLogOutput_;
165    mixLogOutput_ = enable;
166    return lastMixLogOutput;
167}
168
169bool DebugLogger::SetLogPath(const std::string &newLogPath)
170{
171    // make sure not write happend when rename
172    std::lock_guard<std::recursive_mutex> lock(logMutex_);
173    if (newLogPath.empty() and newLogPath != logPath_) {
174        return false;
175    }
176    if (file_ != nullptr) {
177        fclose(file_);
178        file_ = nullptr;
179        if (rename(logPath_.c_str(), newLogPath.c_str()) != 0) {
180            // reopen the old log file path
181            OpenLog();
182            return false;
183        }
184    }
185    logPath_ = newLogPath;
186    return OpenLog();
187}
188
189void DebugLogger::SetLogTags(const std::string &tags)
190{
191    HLOGI(" tags is '%s'", tags.c_str());
192    auto tagLevels = StringSplit(tags, ",");
193    logTagLevelmap_.clear();
194    for (auto tagLevel : tagLevels) {
195        auto tagLevelPair = StringSplit(tagLevel, ":");
196        if (tagLevelPair.size() == 1) { // only tag
197            logTagLevelmap_[tagLevelPair[0]] = LEVEL_MUCH;
198        } else { // tag:level
199            logTagLevelmap_[tagLevelPair[0]] = GetLogLevelByName(tagLevelPair[1].c_str());
200        }
201    }
202    for (auto it = logTagLevelmap_.begin(); it != logTagLevelmap_.end(); it++) {
203        HLOGD(" '%s'='%s'", it->first.c_str(), GetLogLevelName(it->second).c_str());
204    }
205}
206
207DebugLevel DebugLogger::GetLogLevelByTag(const std::string &tag) const
208{
209    if (logTagLevelmap_.count(tag) > 0) {
210        return logTagLevelmap_.at(tag);
211    } else {
212        return GetLogLevel();
213    }
214}
215
216const std::string DebugLogger::GetLogLevelName(DebugLevel level) const
217{
218    return DebugLevelMap.at(level);
219}
220
221DebugLevel DebugLogger::GetLogLevelByName(const std::string &name) const
222{
223    for (auto it = DebugLevelMap.begin(); it != DebugLevelMap.end(); it++) {
224        if (it->second == name) {
225            return it->first;
226        }
227    }
228    // not found ?
229    return LEVEL_MUCH;
230}
231
232// only use for UT
233void DebugLogger::Reset()
234{
235    EnableHiLog(false);
236    SetLogLevel(LEVEL_VERBOSE);
237    Disable(false);
238    SetLogPath(DEFAULT_LOG_PATH);
239    SetLogTags("");
240}
241
242bool DebugLogger::RestoreLog()
243{
244    // use append not write for continually write
245    return OpenLog(logPath_, "a");
246}
247
248bool DebugLogger::OpenLog(const std::string &tempLogPath, const std::string &flags)
249{
250    std::lock_guard<std::recursive_mutex> lock(logMutex_);
251
252    if (logDisabled_) {
253        // don't reopen it when we crash or something else.
254        return false;
255    }
256    if (!tempLogPath.empty()) {
257        if (file_ != nullptr) {
258            fclose(file_);
259        }
260        std::string resolvedPath = CanonicalizeSpecPath(tempLogPath.c_str());
261        file_ = fopen(resolvedPath.c_str(), flags.c_str());
262    }
263    if (file_ != nullptr) {
264        // already open
265        return true;
266    } else {
267        std::string resolvedPath = CanonicalizeSpecPath(logPath_.c_str());
268        file_ = fopen(resolvedPath.c_str(), "w");
269    }
270    if (file_ == nullptr) {
271        fprintf(stdout, "unable save log file to '%s' because '%d'\n", logPath_.c_str(), errno);
272        return false;
273    } else {
274        fseek(file_, 0, SEEK_SET);
275        // ecach log can save 6ms (29ms -> 23ms)
276        fprintf(stdout, "log will save at '%s'\n", logPath_.c_str());
277        return true;
278    }
279}
280
281__attribute__((weak)) DebugLevel DebugLogger::debugLevel_ = LEVEL_DEBUG;
282__attribute__((weak)) bool DebugLogger::logDisabled_ = true;
283std::unique_ptr<DebugLogger> DebugLogger::logInstance_;
284
285DebugLogger *DebugLogger::GetInstance()
286{
287    if (logInstance_ == nullptr) {
288        logInstance_ = std::make_unique<DebugLogger>();
289    }
290    return logInstance_.get();
291}
292} // namespace HiPerf
293} // namespace Developtools
294} // namespace OHOS
295