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 55using namespace std; 56using namespace OHOS::HiviewDFX; 57static RegisterFunc g_registerFunc = nullptr; 58static LogCallback g_logCallback = nullptr; 59static atomic_int g_hiLogGetIdCallCount = 0; 60// protected by static lock guard 61static char g_hiLogLastFatalMessage[MAX_LOG_LEN] = { 0 }; // MAX_lOG_LEN : 1024 62 63HILOG_PUBLIC_API 64extern "C" const char* GetLastFatalMessage() 65{ 66 return g_hiLogLastFatalMessage; 67} 68 69int HiLogRegisterGetIdFun(RegisterFunc registerFunc) 70{ 71 if (g_registerFunc != nullptr) { 72 return -1; 73 } 74 g_registerFunc = registerFunc; 75 return 0; 76} 77 78void 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 92void LOG_SetCallback(LogCallback callback) 93{ 94 g_logCallback = callback; 95} 96 97static 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__ )) 125static 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 157static 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 170static 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 196static 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 215int 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 360int 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 370bool 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