1 /*
2  * Copyright (c) 2021 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 #include <cerrno>
16 #include <cstdarg>
17 #include <cstdio>
18 #include <ctime>
19 #include <fstream>
20 #include <iostream>
21 #include <mutex>
22 #include <securec.h>
23 #include <fcntl.h>
24 #include <sys/stat.h>
25 #include <sys/types.h>
26 
27 #ifdef __LINUX__
28 #include <atomic>
29 #endif
30 
31 #ifndef __WINDOWS__
32 #include <sys/syscall.h>
33 #include <sys/types.h>
34 #else
35 #include <windows.h>
36 #include <memory.h>
37 #endif
38 #include <unistd.h>
39 
40 #include "log_timestamp.h"
41 #include "hilog_trace.h"
42 #include "hilog_inner.h"
43 #include "hilog/log.h"
44 #include "hilog_common.h"
45 #include "vsnprintf_s_p.h"
46 #include "log_utils.h"
47 
48 #if not (defined( __WINDOWS__ ) || defined( __MAC__ ) || defined( __LINUX__ ))
49 #include "properties.h"
50 #include "hilog_input_socket_client.h"
51 #else
52 #include "log_print.h"
53 #endif
54 
55 using namespace std;
56 using namespace OHOS::HiviewDFX;
57 static RegisterFunc g_registerFunc = nullptr;
58 static LogCallback g_logCallback = nullptr;
59 static atomic_int g_hiLogGetIdCallCount = 0;
60 // protected by static lock guard
61 static char g_hiLogLastFatalMessage[MAX_LOG_LEN] = { 0 }; // MAX_lOG_LEN : 1024
62 
63 HILOG_PUBLIC_API
GetLastFatalMessage()64 extern "C" const char* GetLastFatalMessage()
65 {
66     return g_hiLogLastFatalMessage;
67 }
68 
HiLogRegisterGetIdFun(RegisterFunc registerFunc)69 int HiLogRegisterGetIdFun(RegisterFunc registerFunc)
70 {
71     if (g_registerFunc != nullptr) {
72         return -1;
73     }
74     g_registerFunc = registerFunc;
75     return 0;
76 }
77 
HiLogUnregisterGetIdFun(RegisterFunc registerFunc)78 void HiLogUnregisterGetIdFun(RegisterFunc registerFunc)
79 {
80     if (g_registerFunc != registerFunc) {
81         return;
82     }
83 
84     g_registerFunc = nullptr;
85     while (atomic_load(&g_hiLogGetIdCallCount) != 0) {
86         /* do nothing, just wait current callback return */
87     }
88 
89     return;
90 }
91 
LOG_SetCallback(LogCallback callback)92 void LOG_SetCallback(LogCallback callback)
93 {
94     g_logCallback = callback;
95 }
96 
GetFinalLevel(unsigned int domain, const std::string& tag)97 static uint16_t GetFinalLevel(unsigned int domain, const std::string& tag)
98 {
99     // Priority: TagLevel > DomainLevel > GlobalLevel
100     // LOG_LEVEL_MIN is default Level
101 #if not (defined( __WINDOWS__ ) || defined( __MAC__ ) || defined( __LINUX__ ))
102     uint16_t tagLevel = GetTagLevel(tag);
103     if (tagLevel != LOG_LEVEL_MIN) {
104         return tagLevel;
105     }
106     uint16_t domainLevel = GetDomainLevel(domain);
107     if (domainLevel != LOG_LEVEL_MIN) {
108         return domainLevel;
109     }
110     // domain within the range of [DOMAIN_APP_MIN, DOMAIN_APP_MAX] is a js log,
111     // if this js log comes from debuggable hap, set the default level.
112     if ((domain >= DOMAIN_APP_MIN) && (domain <= DOMAIN_APP_MAX)) {
113         static bool isDebuggableHap = IsDebuggableHap();
114         if (isDebuggableHap) {
115             return LOG_LEVEL_MIN;
116         }
117     }
118     return GetGlobalLevel();
119 #else
120     return LOG_LEVEL_MIN;
121 #endif
122 }
123 
124 #if not (defined( __WINDOWS__ ) || defined( __MAC__ ) || defined( __LINUX__ ))
HiLogFlowCtrlProcess(int len, const struct timespec &ts)125 static int HiLogFlowCtrlProcess(int len, const struct timespec &ts)
126 {
127     static uint32_t processQuota = 0;
128     static atomic_int gSumLen = 0;
129     static atomic_int gDropped = 0;
130     static atomic<LogTimeStamp> gStartTime;
131     static LogTimeStamp period(1, 0);
132     static std::atomic_flag isFirstFlag = ATOMIC_FLAG_INIT;
133     if (!isFirstFlag.test_and_set()) {
134         processQuota = GetProcessQuota(GetProgName());
135     }
136     LogTimeStamp tsStart = atomic_load(&gStartTime);
137     LogTimeStamp tsNow(ts);
138     tsStart += period;
139     /* in statistic period(1 second) */
140     if (tsNow > tsStart) { /* new statistic period, return how many lines were dropped */
141         int dropped = atomic_exchange_explicit(&gDropped, 0, memory_order_relaxed);
142         atomic_store(&gStartTime, tsNow);
143         atomic_store(&gSumLen, len);
144         return dropped;
145     } else {
146         uint32_t sumLen = (uint32_t)atomic_load(&gSumLen);
147         if (sumLen > processQuota) { /* over quota, -1 means don't print */
148             atomic_fetch_add_explicit(&gDropped, 1, memory_order_relaxed);
149             return -1;
150         } else { /* under quota, 0 means do print */
151             atomic_fetch_add_explicit(&gSumLen, len, memory_order_relaxed);
152         }
153     }
154     return 0;
155 }
156 
IsNeedProcFlowCtr(const LogType type)157 static bool IsNeedProcFlowCtr(const LogType type)
158 {
159     if (type != LOG_APP) {
160         return false;
161     }
162     //debuggable hap don't perform process flow control
163     static bool isDebuggableHap = IsDebuggableHap();
164     if (IsProcessSwitchOn() && !isDebuggableHap) {
165         return true;
166     }
167     return false;
168 }
169 #else
PrintLog(HilogMsg& header, const char *tag, uint16_t tagLen, const char *fmt, uint16_t fmtLen)170 static int PrintLog(HilogMsg& header, const char *tag, uint16_t tagLen, const char *fmt, uint16_t fmtLen)
171 {
172     LogContent content = {
173         .level = header.level,
174         .type = header.type,
175         .pid = header.pid,
176         .tid = header.tid,
177         .domain = header.domain,
178         .tv_sec = header.tv_sec,
179         .tv_nsec = header.tv_nsec,
180         .mono_sec = header.mono_sec,
181         .tag = tag,
182         .log = fmt,
183     };
184     LogFormat format = {
185         .colorful = false,
186         .timeFormat = FormatTime::TIME,
187         .timeAccuFormat = FormatTimeAccu::MSEC,
188         .year = false,
189         .zone = false,
190     };
191     LogPrintWithFormat(content, format);
192     return RET_SUCCESS;
193 }
194 #endif
195 
LogToKmsg(const LogLevel level, const char *tag, const char* info)196 static int LogToKmsg(const LogLevel level, const char *tag, const char* info)
197 {
198     static int fd = open("/dev/kmsg", O_WRONLY, S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP);
199     if (fd < 0) {
200         printf("open /dev/kmsg failed, fd=%d. \n", fd);
201         return -1;
202     }
203     char logInfo[MAX_LOG_LEN] = {0};
204     if (snprintf_s(logInfo, sizeof(logInfo), sizeof(logInfo) - 1, "<%d>%s: %s\n", level, tag, info) == -1) {
205         logInfo[sizeof(logInfo) - 2] = '\n';  // 2 add \n to tail
206         logInfo[sizeof(logInfo) - 1] = '\0';
207     }
208 #ifdef __LINUX__
209     return TEMP_FAILURE_RETRY(write(fd, logInfo, strlen(logInfo)));
210 #else
211     return write(fd, logInfo, strlen(logInfo));
212 #endif
213 }
214 
HiLogPrintArgs(const LogType type, const LogLevel level, const unsigned int domain, const char *tag, const char *fmt, va_list ap)215 int HiLogPrintArgs(const LogType type, const LogLevel level, const unsigned int domain, const char *tag,
216     const char *fmt, va_list ap)
217 {
218     if ((type != LOG_APP) && ((domain < DOMAIN_OS_MIN) || (domain > DOMAIN_OS_MAX))) {
219         return -1;
220     }
221     if (!HiLogIsLoggable(domain, tag, level)) {
222         return -1;
223     }
224     if (type == LOG_KMSG) {
225         char tmpFmt[MAX_LOG_LEN] = {0};
226         // format va_list info to char*
227         if (vsnprintfp_s(tmpFmt, sizeof(tmpFmt), sizeof(tmpFmt) - 1, true, fmt, ap) == -1) {
228             tmpFmt[sizeof(tmpFmt) - 2] = '\n';  // 2 add \n to tail
229             tmpFmt[sizeof(tmpFmt) - 1] = '\0';
230         }
231         return LogToKmsg(level, tag, tmpFmt);
232     }
233 
234     HilogMsg header = {0};
235     struct timespec ts = {0};
236     (void)clock_gettime(CLOCK_REALTIME, &ts);
237     struct timespec ts_mono = {0};
238     (void)clock_gettime(CLOCK_MONOTONIC, &ts_mono);
239     header.tv_sec = static_cast<uint32_t>(ts.tv_sec);
240     header.tv_nsec = static_cast<uint32_t>(ts.tv_nsec);
241     header.mono_sec = static_cast<uint32_t>(ts_mono.tv_sec);
242 
243     char buf[MAX_LOG_LEN] = {0};
244     char *logBuf = buf;
245     int traceBufLen = 0;
246     int ret;
247     /* print traceid */
248     if (g_registerFunc != nullptr) {
249         uint64_t chainId = 0;
250         uint32_t flag = 0;
251         uint64_t spanId = 0;
252         uint64_t parentSpanId = 0;
253         ret = -1;  /* default value -1: invalid trace id */
254         atomic_fetch_add_explicit(&g_hiLogGetIdCallCount, 1, memory_order_relaxed);
255         RegisterFunc func = g_registerFunc;
256         if (func != nullptr) {
257             ret = func(&chainId, &flag, &spanId, &parentSpanId);
258         }
259         atomic_fetch_sub_explicit(&g_hiLogGetIdCallCount, 1, memory_order_relaxed);
260         if (ret == 0) {  /* 0: trace id with span id */
261             traceBufLen = snprintf_s(logBuf, MAX_LOG_LEN, MAX_LOG_LEN - 1, "[%llx, %llx, %llx] ",
262                 (unsigned long long)chainId, (unsigned long long)spanId, (unsigned long long)parentSpanId);
263         } else if (ret != -1) {  /* trace id without span id, -1: invalid trace id */
264             traceBufLen = snprintf_s(logBuf, MAX_LOG_LEN, MAX_LOG_LEN - 1, "[%llx] ",
265                 (unsigned long long)chainId);
266         }
267         if (traceBufLen > 0) {
268             logBuf += traceBufLen;
269         } else {
270             traceBufLen = 0;
271         }
272     }
273 
274     /* format log string */
275 #if not (defined( __WINDOWS__ ) || defined( __MAC__ ) || defined( __LINUX__ ))
276     bool debug = IsDebugOn();
277     bool priv = (!debug) && IsPrivateSwitchOn();
278 #else
279     bool priv = true;
280 #endif
281 
282 #ifdef __clang__
283 /* code specific to clang compiler */
284 #pragma clang diagnostic push
285 #pragma clang diagnostic ignored "-Wformat-nonliteral"
286 #elif __GNUC__
287 /* code for GNU C compiler */
288 #pragma GCC diagnostic push
289 #pragma GCC diagnostic ignored "-Wformat-nonliteral"
290 #endif
291     vsnprintfp_s(logBuf, MAX_LOG_LEN - traceBufLen, MAX_LOG_LEN - traceBufLen - 1, priv, fmt, ap);
292     LogCallback logCallbackFunc = g_logCallback;
293     if (logCallbackFunc != nullptr) {
294         logCallbackFunc(type, level, domain, tag, logBuf);
295     }
296 #ifdef __clang__
297 #pragma clang diagnostic pop
298 #elif __GNUC__
299 #pragma GCC diagnostic pop
300 #endif
301 
302     /* fill header info */
303     auto tagLen = strnlen(tag, MAX_TAG_LEN - 1);
304     auto logLen = strnlen(buf, MAX_LOG_LEN - 1);
305     header.type = type;
306     header.level = level;
307 #ifndef __RECV_MSG_WITH_UCRED_
308 #if defined(is_ohos) && is_ohos
309     header.pid = static_cast<uint32_t>(getprocpid());
310 #elif not defined(__WINDOWS__)
311     header.pid = getpid();
312 #else
313     header.pid = static_cast<uint32_t>(GetCurrentProcessId());
314 #endif
315 #endif
316 #ifdef __WINDOWS__
317     header.tid = static_cast<uint32_t>(GetCurrentThreadId());
318 #elif defined(__MAC__)
319     uint64_t tid;
320     pthread_threadid_np(NULL, &tid);
321     header.tid = static_cast<uint32_t>(tid);
322 #elif defined(__OHOS__)
323     header.tid = static_cast<uint32_t>(getproctid());
324 #else
325     header.tid = static_cast<uint32_t>(syscall(SYS_gettid));
326 #endif
327     header.domain = domain;
328 
329     if (level == LOG_FATAL) {
330         static std::mutex fatalMessageBufMutex;
331         std::lock_guard<std::mutex> lock(fatalMessageBufMutex);
332         (void)memcpy_s(g_hiLogLastFatalMessage, sizeof(g_hiLogLastFatalMessage), buf, sizeof(buf));
333     }
334 
335 #if not (defined( __WINDOWS__ ) || defined( __MAC__ ) || defined( __LINUX__ ))
336     /* flow control */
337     if (!debug && IsNeedProcFlowCtr(type)) {
338         ret = HiLogFlowCtrlProcess(tagLen + logLen - traceBufLen, ts_mono);
339         if (ret < 0) {
340             return ret;
341         } else if (ret > 0) {
342             static const char P_LIMIT_TAG[] = "LOGLIMIT";
343             uint16_t level = header.level;
344             header.level = LOG_WARN;
345             char dropLogBuf[MAX_LOG_LEN] = {0};
346             if (snprintf_s(dropLogBuf, MAX_LOG_LEN, MAX_LOG_LEN - 1,
347                 "==LOGS OVER PROC QUOTA, %d DROPPED==", ret) > 0) {
348                 HilogWriteLogMessage(&header, P_LIMIT_TAG, strlen(P_LIMIT_TAG) + 1, dropLogBuf,
349                     strnlen(dropLogBuf, MAX_LOG_LEN - 1) + 1);
350             }
351             header.level = level;
352         }
353     }
354     return HilogWriteLogMessage(&header, tag, tagLen + 1, buf, logLen + 1);
355 #else
356     return PrintLog(header, tag, tagLen + 1, buf, logLen + 1);
357 #endif
358 }
359 
HiLogPrint(LogType type, LogLevel level, unsigned int domain, const char *tag, const char *fmt, ...)360 int HiLogPrint(LogType type, LogLevel level, unsigned int domain, const char *tag, const char *fmt, ...)
361 {
362     int ret;
363     va_list ap;
364     va_start(ap, fmt);
365     ret = HiLogPrintArgs(type, level, domain, tag, fmt, ap);
366     va_end(ap);
367     return ret;
368 }
369 
HiLogIsLoggable(unsigned int domain, const char *tag, LogLevel level)370 bool HiLogIsLoggable(unsigned int domain, const char *tag, LogLevel level)
371 {
372     if ((level <= LOG_LEVEL_MIN) || (level >= LOG_LEVEL_MAX) || (tag == nullptr) || (domain >= DOMAIN_OS_MAX)) {
373         return false;
374     }
375     if (level < GetFinalLevel(domain, tag)) {
376         return false;
377     }
378     return true;
379 }
380