/* * Copyright (c) Huawei Technologies Co., Ltd. 2021. All rights reserved. * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. * You may obtain a copy of the License at * * http://www.apache.org/licenses/LICENSE-2.0 * * Unless required by applicable law or agreed to in writing, software * distributed under the License is distributed on an "AS IS" BASIS, * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. * See the License for the specific language governing permissions and * limitations under the License. */ #include "hilog_plugin.h" #include "securec.h" #include #include #include #include #include #include #include #include #include #include "common.h" #include "hilog_plugin_result.pbencoder.h" namespace { using namespace OHOS::Developtools::Profiler; std::atomic g_id(1); const int DEC_BASE = 10; const int TIME_HOUR_WIDTH = 5; const int TIME_SEC_WIDTH = 14; const int TIME_NS_WIDTH = 24; const int FILE_NAME_LEN = 15; const int TIME_BUFF_LEN = 32; const int PIPE_SIZE_RATIO = 8; const int BYTE_BUFFER_SIZE = 1024; const int BASE_YEAR = 1900; const int MAX_BUFFER_LEN = 8192; const std::string DEFAULT_LOG_PATH("/data/local/tmp/"); FileCache g_fileCache(DEFAULT_LOG_PATH); const std::string BIN_COMMAND("/system/bin/hilog"); } // namespace HilogPlugin::HilogPlugin() : fp_(nullptr, nullptr) {} HilogPlugin::~HilogPlugin() { PROFILER_LOG_INFO(LOG_CORE, "%s: ready!", __func__); std::unique_lock locker(mutex_); if (running_) { running_ = false; if (workThread_.joinable()) { workThread_.join(); } } locker.unlock(); if (protoConfig_.need_record()) { g_fileCache.Close(); } if (fp_ != nullptr) { fp_.reset(); } PROFILER_LOG_INFO(LOG_CORE, "%s: success!", __func__); } int HilogPlugin::Start(const uint8_t* configData, uint32_t configSize) { CHECK_TRUE(protoConfig_.ParseFromArray(configData, configSize) > 0, -1, "HilogPlugin: ParseFromArray failed"); if (protoConfig_.need_clear()) { std::vector cmdArg; cmdArg.emplace_back(BIN_COMMAND); // exe file path cmdArg.emplace_back("hilog"); // exe file name cmdArg.emplace_back("-r"); volatile pid_t childPid = -1; int pipeFds[2] = {-1, -1}; FILE* fp = COMMON::CustomPopen(cmdArg, "r", pipeFds, childPid); CHECK_NOTNULL(fp, -1, "%s:clear hilog error", __func__); COMMON::CustomPclose(fp, pipeFds, childPid); } InitHilogCmd(); fp_ = std::unique_ptr>( COMMON::CustomPopen(fullCmd_, "r", pipeFds_, childPid_, true), [this](FILE* fp) -> int { return COMMON::CustomPclose(fp, pipeFds_, childPid_, true); }); if (protoConfig_.need_record()) { OpenLogFile(); } CHECK_NOTNULL(resultWriter_, -1, "HilogPlugin: Writer is no set!!"); CHECK_NOTNULL(resultWriter_->write, -1, "HilogPlugin: Writer.write is no set!!"); CHECK_NOTNULL(resultWriter_->flush, -1, "HilogPlugin: Writer.flush is no set!!"); g_id = 1; std::unique_lock locker(mutex_); running_ = true; locker.unlock(); int oldPipeSize = fcntl(fileno(fp_.get()), F_GETPIPE_SZ); fcntl(fileno(fp_.get()), F_SETPIPE_SZ, oldPipeSize * PIPE_SIZE_RATIO); int pipeSize = fcntl(fileno(fp_.get()), F_GETPIPE_SZ); PROFILER_LOG_INFO(LOG_CORE, "{fp = %d, pipeSize=%d, oldPipeSize=%d}", fileno(fp_.get()), pipeSize, oldPipeSize); workThread_ = std::thread([this] { this->Run(); }); return 0; } int HilogPlugin::Stop() { PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin: ready stop thread!"); std::unique_lock locker(mutex_); running_ = false; COMMON::CustomPUnblock(pipeFds_); locker.unlock(); if (workThread_.joinable()) { workThread_.join(); } if (protoConfig_.need_record() && !dataBuffer_.empty()) { g_fileCache.Write(dataBuffer_.data(), dataBuffer_.size()); dataBuffer_.erase(dataBuffer_.begin(), dataBuffer_.end()); } PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin: stop thread success!"); if (protoConfig_.need_record()) { g_fileCache.Close(); } fp_.reset(); PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin: stop success!"); return 0; } int HilogPlugin::SetWriter(WriterStruct* writer) { resultWriter_ = writer; return 0; } bool HilogPlugin::OpenLogFile() { char name[FILE_NAME_LEN] = {0}; GetDateTime(name, sizeof(name)); CHECK_TRUE(g_fileCache.Open(name), false, "HilogPlugin:%s failed!", __func__); return true; } std::string HilogPlugin::GetlevelCmd() { std::string levelCmd = ""; switch (protoConfig_.log_level()) { case ERROR: levelCmd = "E"; break; case INFO: levelCmd = "I"; break; case DEBUG: levelCmd = "D"; break; case WARN: levelCmd = "W"; break; case FATAL: levelCmd = "F"; break; default: break; } return levelCmd; } void HilogPlugin::InitHilogCmd() { fullCmd_.emplace_back(BIN_COMMAND); // exe file path fullCmd_.emplace_back("hilog"); // exe file name if (protoConfig_.pid() > 0) { fullCmd_.emplace_back("-P"); fullCmd_.emplace_back(std::to_string(protoConfig_.pid())); } if (GetlevelCmd().length() > 0) { fullCmd_.emplace_back("-L"); fullCmd_.emplace_back(GetlevelCmd()); } fullCmd_.emplace_back("--format"); fullCmd_.emplace_back("nsec"); } void HilogPlugin::Run(void) { PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin::Run start!"); std::unique_ptr buffer = std::make_unique(MAX_BUFFER_LEN); std::unique_ptr dataProto = nullptr; std::unique_ptr hilogInfo = nullptr; if (resultWriter_->isProtobufSerialize) { dataProto = std::make_unique(); } else { hilogInfo = std::make_unique(resultWriter_->startReport(resultWriter_)); } time_t startTm = time(nullptr); struct tm* pTime = localtime(&startTm); char startTime[FILE_NAME_LEN] = {0}; if (pTime != nullptr) { (void)snprintf_s(startTime, FILE_NAME_LEN, FILE_NAME_LEN - 1, "%02d-%02d %02d:%02d:%02d", pTime->tm_mon + 1, pTime->tm_mday, pTime->tm_hour, pTime->tm_min, pTime->tm_sec); } while (running_) { if (fgets(reinterpret_cast(buffer.get()), MAX_BUFFER_LEN - 1, fp_.get()) == nullptr) { continue; } if ((strlen(reinterpret_cast(buffer.get())) + 1) == (MAX_BUFFER_LEN - 1)) { PROFILER_LOG_ERROR(LOG_CORE, "HilogPlugin:data length is greater than the MAX_BUFFER_LEN(%d)", MAX_BUFFER_LEN); } auto cptr = reinterpret_cast(buffer.get()); std::string curTime = cptr; curTime = curTime.substr(0, TIME_SEC_WIDTH); if (curTime < startTime) { continue; } if (resultWriter_->isProtobufSerialize) { ParseLogLineData(cptr, strlen(cptr), dataProto.get()); if (dataProto->ByteSizeLong() >= BYTE_BUFFER_SIZE) { FlushData(dataProto.get()); dataProto.reset(); dataProto = std::make_unique(); } } else { ParseLogLineData(cptr, strlen(cptr), hilogInfo.get()); if (hilogInfo->Size() >= BYTE_BUFFER_SIZE) { FlushDataOptimize(hilogInfo.get()); hilogInfo.reset(); hilogInfo = std::make_unique(resultWriter_->startReport(resultWriter_)); } } if (protoConfig_.need_record() && dataBuffer_.size() >= BYTE_BUFFER_SIZE) { g_fileCache.Write(dataBuffer_.data(), dataBuffer_.size()); dataBuffer_.erase(dataBuffer_.begin(), dataBuffer_.end()); } } if (resultWriter_->isProtobufSerialize) { FlushData(dataProto.get()); dataProto.reset(); } else { FlushDataOptimize(hilogInfo.get()); hilogInfo.reset(); } PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin::Run done!"); } template void HilogPlugin::ParseLogLineInfo(const char* data, size_t len, T& hilogLineInfo) { if (data == nullptr || len < TIME_NS_WIDTH) { PROFILER_LOG_ERROR(LOG_CORE, "HilogPlugin:%s param invalid", __func__); return; } for (size_t i = 0; i < len && protoConfig_.need_record(); i++) { dataBuffer_.push_back(data[i]); } SetHilogLineDetails(data, hilogLineInfo); return; } template void HilogPlugin::ParseLogLineData(const char* data, size_t len, T hilogInfoProto) { CHECK_NOTNULL(data, NO_RETVAL, "data is nullptr"); if (*data >= '0' && *data <= '9') { auto* info = hilogInfoProto->add_info(); ParseLogLineInfo(data, len, *info); info->set_id(g_id); g_id++; } } template bool HilogPlugin::SetHilogLineDetails(const char* data, T& hilogLineInfo) { char* end = nullptr; struct timespec ts = {0}; char* pTmp = const_cast(data); TimeStringToNS(data, &ts); auto* detail = hilogLineInfo.mutable_detail(); detail->set_tv_sec(ts.tv_sec); detail->set_tv_nsec(ts.tv_nsec); pTmp = pTmp + TIME_SEC_WIDTH; CHECK_TRUE(FindFirstSpace(&pTmp), false, "HilogPlugin:FindFirstSpace failed!"); uint32_t value = static_cast(strtoul(pTmp, &end, DEC_BASE)); CHECK_TRUE(value > 0, false, "HilogPlugin:strtoull pid failed!"); detail->set_pid(value); pTmp = end; value = static_cast(strtoul(pTmp, &end, DEC_BASE)); CHECK_TRUE(value > 0, false, "HilogPlugin:strtoull tid failed!"); detail->set_tid(value); pTmp = end; CHECK_TRUE(RemoveSpaces(&pTmp), false, "HilogPlugin:RemoveSpaces failed!"); detail->set_level(*pTmp); pTmp++; CHECK_TRUE(RemoveSpaces(&pTmp), false, "HilogPlugin:RemoveSpaces failed!"); if (*pTmp >= '0' && *pTmp <= '9') { while (*pTmp != '/') { // 找 '/' if (*pTmp == '\0' || *pTmp == '\n') { return false; } pTmp++; } pTmp++; end = pTmp; } else if ((*pTmp >= 'a' && *pTmp <= 'z') || (*pTmp >= 'A' && *pTmp <= 'Z')) { end = pTmp; } int index = 1; if (end == nullptr) { return false; } while (*pTmp != ':') { // 结束符 ':' if (*pTmp == '\0' || *pTmp == '\n') { return false; } pTmp++; index++; } detail->set_tag(std::string(end, end + index - 1)); pTmp++; CHECK_TRUE(RemoveSpaces(&pTmp), false, "HilogPlugin: RemoveSpaces failed!"); size_t dataLen = strlen(pTmp) > 1 ? strlen(pTmp) -1 : 0; if (google::protobuf::internal::IsStructurallyValidUTF8(pTmp, dataLen)) { hilogLineInfo.set_context(pTmp, dataLen); // - \n } else { PROFILER_LOG_ERROR(LOG_CORE, "HilogPlugin: log context include invalid UTF-8 data"); hilogLineInfo.set_context(""); } return true; } bool HilogPlugin::FindFirstNum(char** p) { CHECK_NOTNULL(*p, false, "HilogPlugin:%s", __func__); while (**p > '9' || **p < '0') { if (**p == '\0' || **p == '\n') { return false; } (*p)++; } return true; } bool HilogPlugin::RemoveSpaces(char** p) { CHECK_NOTNULL(*p, false, "HilogPlugin:%s", __func__); if (**p == '\0' || **p == '\n') { return false; } while (**p == ' ') { (*p)++; if (**p == '\0' || **p == '\n') { return false; } } return true; } bool HilogPlugin::FindFirstSpace(char** p) { CHECK_NOTNULL(*p, false, "HilogPlugin:%s", __func__); while (**p != ' ') { if (**p == '\0' || **p == '\n') { return false; } (*p)++; } return true; } bool HilogPlugin::StringToL(const char* word, long& value) { char* end = nullptr; errno = 0; value = strtol(word, &end, DEC_BASE); if ((errno == ERANGE && (value == LONG_MAX)) || (errno != 0 && value == 0)) { return false; } else if (end == word && (*word >= '0' && *word <= '9')) { return false; } return true; } bool HilogPlugin::TimeStringToNS(const char* data, struct timespec *tsTime) { struct tm tmTime = {0}; struct tm result; time_t timetTime; char* end = nullptr; char* pTmp = nullptr; time_t nSeconds = time(nullptr); uint32_t nsec = 0; long fixHour = 0; if (localtime_r(&nSeconds, &result) == nullptr) { const int bufSize = 128; char buf[bufSize] = { 0 }; strerror_r(errno, buf, bufSize); PROFILER_LOG_ERROR(LOG_CORE, "HilogPlugin: get localtime failed!, errno(%d:%s)", errno, buf); return false; } tmTime.tm_year = result.tm_year; strptime(data, "%m-%d %H:%M:%S", &tmTime); pTmp = const_cast(data) + TIME_HOUR_WIDTH; CHECK_TRUE(StringToL(pTmp, fixHour), false, "%s:strtol fixHour failed", __func__); if (static_cast(fixHour) != tmTime.tm_hour) { // hours since midnight - [0, 23] PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin: hour(%d) <==> fix hour(%ld)!", tmTime.tm_hour, fixHour); tmTime.tm_hour = fixHour; } pTmp = const_cast(data) + TIME_SEC_WIDTH; FindFirstNum(&pTmp); nsec = static_cast(strtoul(pTmp, &end, DEC_BASE)); CHECK_TRUE(nsec > 0, false, "%s:strtoull nsec failed", __func__); timetTime = mktime(&tmTime); tsTime->tv_sec = timetTime; tsTime->tv_nsec = nsec; char buff[TIME_BUFF_LEN] = {0}; if (snprintf_s(buff, sizeof(buff), sizeof(buff) - 1, "%ld.%09u\n", timetTime, nsec) < 0) { PROFILER_LOG_ERROR(LOG_CORE, "%s:snprintf_s error", __func__); } size_t buffSize = strlen(buff); for (size_t i = 0; i < buffSize && protoConfig_.need_record(); i++) { dataBuffer_.push_back(buff[i]); } return true; } int HilogPlugin::GetDateTime(char* psDateTime, uint32_t size) { CHECK_NOTNULL(psDateTime, -1, "HilogPlugin:%s param invalid", __func__); CHECK_TRUE(size > 1, -1, "HilogPlugin:%s param invalid!", __func__); time_t nSeconds; struct tm* pTM; nSeconds = time(nullptr); pTM = localtime(&nSeconds); if (pTM == nullptr) { const int bufSize = 128; char buf[bufSize] = { 0 }; strerror_r(errno, buf, bufSize); PROFILER_LOG_ERROR(LOG_CORE, "HilogPlugin: get localtime failed!, errno(%d:%s)", errno, buf); return -1; } if (snprintf_s(psDateTime, size, size - 1, "%04d%02d%02d%02d%02d%02d", pTM->tm_year + BASE_YEAR, pTM->tm_mon + 1, pTM->tm_mday, pTM->tm_hour, pTM->tm_min, pTM->tm_sec) < 0) { PROFILER_LOG_ERROR(LOG_CORE, "%s:snprintf_s error", __func__); } return 0; } template void HilogPlugin::FlushData(const T hilogLineProto) { protoBuffer_.resize(hilogLineProto->ByteSizeLong()); hilogLineProto->SerializeToArray(protoBuffer_.data(), protoBuffer_.size()); resultWriter_->write(resultWriter_, protoBuffer_.data(), protoBuffer_.size()); resultWriter_->flush(resultWriter_); } template void HilogPlugin::FlushDataOptimize(const T hilogLineProto) { int messageLen = hilogLineProto->Finish(); resultWriter_->finishReport(resultWriter_, messageLen); resultWriter_->flush(resultWriter_); }