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 (g_registerFunc != 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     if (g_logCallback != nullptr) {
293         g_logCallback(type, level, domain, tag, logBuf);
294     }
295 #ifdef __clang__
296 #pragma clang diagnostic pop
297 #elif __GNUC__
298 #pragma GCC diagnostic pop
299 #endif
300 
301     /* fill header info */
302     auto tagLen = strnlen(tag, MAX_TAG_LEN - 1);
303     auto logLen = strnlen(buf, MAX_LOG_LEN - 1);
304     header.type = type;
305     header.level = level;
306 #ifndef __RECV_MSG_WITH_UCRED_
307 #if defined(is_ohos) && is_ohos
308     header.pid = static_cast<uint32_t>(getprocpid());
309 #elif not defined(__WINDOWS__)
310     header.pid = getpid();
311 #else
312     header.pid = static_cast<uint32_t>(GetCurrentProcessId());
313 #endif
314 #endif
315 #ifdef __WINDOWS__
316     header.tid = static_cast<uint32_t>(GetCurrentThreadId());
317 #elif defined(__MAC__)
318     uint64_t tid;
319     pthread_threadid_np(NULL, &tid);
320     header.tid = static_cast<uint32_t>(tid);
321 #elif defined(__OHOS__)
322     header.tid = static_cast<uint32_t>(getproctid());
323 #else
324     header.tid = static_cast<uint32_t>(syscall(SYS_gettid));
325 #endif
326     header.domain = domain;
327 
328     if (level == LOG_FATAL) {
329         static std::mutex fatalMessageBufMutex;
330         std::lock_guard<std::mutex> lock(fatalMessageBufMutex);
331         (void)memcpy_s(g_hiLogLastFatalMessage, sizeof(g_hiLogLastFatalMessage), buf, sizeof(buf));
332     }
333 
334 #if not (defined( __WINDOWS__ ) || defined( __MAC__ ) || defined( __LINUX__ ))
335     /* flow control */
336     if (!debug && IsNeedProcFlowCtr(type)) {
337         ret = HiLogFlowCtrlProcess(tagLen + logLen - traceBufLen, ts_mono);
338         if (ret < 0) {
339             return ret;
340         } else if (ret > 0) {
341             static const char P_LIMIT_TAG[] = "LOGLIMIT";
342             uint16_t level = header.level;
343             header.level = LOG_WARN;
344             char dropLogBuf[MAX_LOG_LEN] = {0};
345             if (snprintf_s(dropLogBuf, MAX_LOG_LEN, MAX_LOG_LEN - 1,
346                 "==LOGS OVER PROC QUOTA, %d DROPPED==", ret) > 0) {
347                 HilogWriteLogMessage(&header, P_LIMIT_TAG, strlen(P_LIMIT_TAG) + 1, dropLogBuf,
348                     strnlen(dropLogBuf, MAX_LOG_LEN - 1) + 1);
349             }
350             header.level = level;
351         }
352     }
353     return HilogWriteLogMessage(&header, tag, tagLen + 1, buf, logLen + 1);
354 #else
355     return PrintLog(header, tag, tagLen + 1, buf, logLen + 1);
356 #endif
357 }
358 
HiLogPrint(LogType type,LogLevel level,unsigned int domain,const char * tag,const char * fmt,...)359 int HiLogPrint(LogType type, LogLevel level, unsigned int domain, const char *tag, const char *fmt, ...)
360 {
361     int ret;
362     va_list ap;
363     va_start(ap, fmt);
364     ret = HiLogPrintArgs(type, level, domain, tag, fmt, ap);
365     va_end(ap);
366     return ret;
367 }
368 
HiLogIsLoggable(unsigned int domain,const char * tag,LogLevel level)369 bool HiLogIsLoggable(unsigned int domain, const char *tag, LogLevel level)
370 {
371     if ((level <= LOG_LEVEL_MIN) || (level >= LOG_LEVEL_MAX) || (tag == nullptr) || (domain >= DOMAIN_OS_MAX)) {
372         return false;
373     }
374     if (level < GetFinalLevel(domain, tag)) {
375         return false;
376     }
377     return true;
378 }
379