1 /*
2 * Copyright (c) Huawei Technologies Co., Ltd. 2021. All rights reserved.
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 "hilog_plugin.h"
16 #include "securec.h"
17
18 #include <fcntl.h>
19 #include <cinttypes>
20 #include <csignal>
21 #include <sstream>
22 #include <cstdio>
23 #include <sys/syscall.h>
24 #include <sys/types.h>
25 #include <sys/wait.h>
26 #include <unistd.h>
27 #include "common.h"
28 #include "hilog_plugin_result.pbencoder.h"
29
30 namespace {
31 using namespace OHOS::Developtools::Profiler;
32 std::atomic<uint64_t> g_id(1);
33 const int DEC_BASE = 10;
34 const int TIME_HOUR_WIDTH = 5;
35 const int TIME_SEC_WIDTH = 14;
36 const int TIME_NS_WIDTH = 24;
37 const int FILE_NAME_LEN = 15;
38 const int TIME_BUFF_LEN = 32;
39 const int PIPE_SIZE_RATIO = 8;
40 const int BYTE_BUFFER_SIZE = 1024;
41 const int BASE_YEAR = 1900;
42 const int MAX_BUFFER_LEN = 8192;
43 const std::string DEFAULT_LOG_PATH("/data/local/tmp/");
44 FileCache g_fileCache(DEFAULT_LOG_PATH);
45 const std::string BIN_COMMAND("/system/bin/hilog");
46 } // namespace
47
HilogPlugin()48 HilogPlugin::HilogPlugin() : fp_(nullptr, nullptr) {}
49
~HilogPlugin()50 HilogPlugin::~HilogPlugin()
51 {
52 PROFILER_LOG_INFO(LOG_CORE, "%s: ready!", __func__);
53 std::unique_lock<std::mutex> locker(mutex_);
54 if (running_) {
55 running_ = false;
56 if (workThread_.joinable()) {
57 workThread_.join();
58 }
59 }
60 locker.unlock();
61
62 if (protoConfig_.need_record()) {
63 g_fileCache.Close();
64 }
65 if (fp_ != nullptr) {
66 fp_.reset();
67 }
68 PROFILER_LOG_INFO(LOG_CORE, "%s: success!", __func__);
69 }
70
Start(const uint8_t * configData,uint32_t configSize)71 int HilogPlugin::Start(const uint8_t* configData, uint32_t configSize)
72 {
73 CHECK_TRUE(protoConfig_.ParseFromArray(configData, configSize) > 0, -1, "HilogPlugin: ParseFromArray failed");
74 if (protoConfig_.need_clear()) {
75 std::vector<std::string> cmdArg;
76
77 cmdArg.emplace_back(BIN_COMMAND); // exe file path
78 cmdArg.emplace_back("hilog"); // exe file name
79 cmdArg.emplace_back("-r");
80 volatile pid_t childPid = -1;
81 int pipeFds[2] = {-1, -1};
82 FILE* fp = COMMON::CustomPopen(cmdArg, "r", pipeFds, childPid);
83 CHECK_NOTNULL(fp, -1, "%s:clear hilog error", __func__);
84 COMMON::CustomPclose(fp, pipeFds, childPid);
85 }
86
87 InitHilogCmd();
88 fp_ = std::unique_ptr<FILE, std::function<int (FILE*)>>(
89 COMMON::CustomPopen(fullCmd_, "r", pipeFds_, childPid_, true), [this](FILE* fp) -> int {
90 return COMMON::CustomPclose(fp, pipeFds_, childPid_, true);
91 });
92
93 if (protoConfig_.need_record()) {
94 OpenLogFile();
95 }
96
97 CHECK_NOTNULL(resultWriter_, -1, "HilogPlugin: Writer is no set!!");
98 CHECK_NOTNULL(resultWriter_->write, -1, "HilogPlugin: Writer.write is no set!!");
99 CHECK_NOTNULL(resultWriter_->flush, -1, "HilogPlugin: Writer.flush is no set!!");
100 g_id = 1;
101 std::unique_lock<std::mutex> locker(mutex_);
102 running_ = true;
103 locker.unlock();
104
105 int oldPipeSize = fcntl(fileno(fp_.get()), F_GETPIPE_SZ);
106 fcntl(fileno(fp_.get()), F_SETPIPE_SZ, oldPipeSize * PIPE_SIZE_RATIO);
107 int pipeSize = fcntl(fileno(fp_.get()), F_GETPIPE_SZ);
108 PROFILER_LOG_INFO(LOG_CORE, "{fp = %d, pipeSize=%d, oldPipeSize=%d}", fileno(fp_.get()), pipeSize, oldPipeSize);
109
110 workThread_ = std::thread(&HilogPlugin::Run, this);
111
112 return 0;
113 }
114
Stop()115 int HilogPlugin::Stop()
116 {
117 PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin: ready stop thread!");
118 std::unique_lock<std::mutex> locker(mutex_);
119 running_ = false;
120 COMMON::CustomPUnblock(pipeFds_);
121 locker.unlock();
122 if (workThread_.joinable()) {
123 workThread_.join();
124 }
125 if (protoConfig_.need_record() && !dataBuffer_.empty()) {
126 g_fileCache.Write(dataBuffer_.data(), dataBuffer_.size());
127 dataBuffer_.erase(dataBuffer_.begin(), dataBuffer_.end());
128 }
129 PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin: stop thread success!");
130 if (protoConfig_.need_record()) {
131 g_fileCache.Close();
132 }
133 fp_.reset();
134
135 PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin: stop success!");
136 return 0;
137 }
138
SetWriter(WriterStruct * writer)139 int HilogPlugin::SetWriter(WriterStruct* writer)
140 {
141 resultWriter_ = writer;
142 return 0;
143 }
144
OpenLogFile()145 bool HilogPlugin::OpenLogFile()
146 {
147 char name[FILE_NAME_LEN] = {0};
148 GetDateTime(name, sizeof(name));
149 CHECK_TRUE(g_fileCache.Open(name), false, "HilogPlugin:%s failed!", __func__);
150
151 return true;
152 }
153
GetlevelCmd()154 std::string HilogPlugin::GetlevelCmd()
155 {
156 std::string levelCmd = "";
157 switch (protoConfig_.log_level()) {
158 case ERROR:
159 levelCmd = "E";
160 break;
161 case INFO:
162 levelCmd = "I";
163 break;
164 case DEBUG:
165 levelCmd = "D";
166 break;
167 case WARN:
168 levelCmd = "W";
169 break;
170 case FATAL:
171 levelCmd = "F";
172 break;
173 default:
174 break;
175 }
176
177 return levelCmd;
178 }
179
InitHilogCmd()180 void HilogPlugin::InitHilogCmd()
181 {
182 fullCmd_.emplace_back(BIN_COMMAND); // exe file path
183 fullCmd_.emplace_back("hilog"); // exe file name
184
185 if (protoConfig_.pid() > 0) {
186 fullCmd_.emplace_back("-P");
187 fullCmd_.emplace_back(std::to_string(protoConfig_.pid()));
188 }
189 if (GetlevelCmd().length() > 0) {
190 fullCmd_.emplace_back("-L");
191 fullCmd_.emplace_back(GetlevelCmd());
192 }
193
194 fullCmd_.emplace_back("--format");
195 fullCmd_.emplace_back("nsec");
196 }
197
Run(void)198 void HilogPlugin::Run(void)
199 {
200 PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin::Run start!");
201 std::unique_ptr<uint8_t[]> buffer = std::make_unique<uint8_t[]>(MAX_BUFFER_LEN);
202
203 std::unique_ptr<HilogInfo> dataProto = nullptr;
204 std::unique_ptr<ProtoEncoder::HilogInfo> hilogInfo = nullptr;
205 if (resultWriter_->isProtobufSerialize) {
206 dataProto = std::make_unique<HilogInfo>();
207 } else {
208 hilogInfo = std::make_unique<ProtoEncoder::HilogInfo>(resultWriter_->startReport(resultWriter_));
209 }
210
211 while (running_) {
212 if (fgets(reinterpret_cast<char*>(buffer.get()), MAX_BUFFER_LEN - 1, fp_.get()) == nullptr) {
213 continue;
214 }
215
216 if ((strlen(reinterpret_cast<char*>(buffer.get())) + 1) == (MAX_BUFFER_LEN - 1)) {
217 PROFILER_LOG_ERROR(LOG_CORE,
218 "HilogPlugin:data length is greater than the MAX_BUFFER_LEN(%d)", MAX_BUFFER_LEN);
219 }
220
221 auto cptr = reinterpret_cast<char*>(buffer.get());
222 if (resultWriter_->isProtobufSerialize) {
223 ParseLogLineData(cptr, strlen(cptr), dataProto.get());
224
225 if (dataProto->ByteSizeLong() >= BYTE_BUFFER_SIZE) {
226 FlushData(dataProto.get());
227 dataProto.reset();
228 dataProto = std::make_unique<HilogInfo>();
229 }
230 } else {
231 ParseLogLineData(cptr, strlen(cptr), hilogInfo.get());
232
233 if (hilogInfo->Size() >= BYTE_BUFFER_SIZE) {
234 FlushDataOptimize(hilogInfo.get());
235 hilogInfo.reset();
236 hilogInfo = std::make_unique<ProtoEncoder::HilogInfo>(resultWriter_->startReport(resultWriter_));
237 }
238 }
239
240 if (protoConfig_.need_record() && dataBuffer_.size() >= BYTE_BUFFER_SIZE) {
241 g_fileCache.Write(dataBuffer_.data(), dataBuffer_.size());
242 dataBuffer_.erase(dataBuffer_.begin(), dataBuffer_.end());
243 }
244 }
245
246 if (resultWriter_->isProtobufSerialize) {
247 FlushData(dataProto.get());
248 dataProto.reset();
249 } else {
250 FlushDataOptimize(hilogInfo.get());
251 hilogInfo.reset();
252 }
253 PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin::Run done!");
254 }
255
ParseLogLineInfo(const char * data,size_t len,T & hilogLineInfo)256 template <typename T> void HilogPlugin::ParseLogLineInfo(const char* data, size_t len, T& hilogLineInfo)
257 {
258 if (data == nullptr || len < TIME_NS_WIDTH) {
259 PROFILER_LOG_ERROR(LOG_CORE, "HilogPlugin:%s param invalid", __func__);
260 return;
261 }
262
263 for (size_t i = 0; i < len && protoConfig_.need_record(); i++) {
264 dataBuffer_.push_back(data[i]);
265 }
266
267 SetHilogLineDetails(data, hilogLineInfo);
268 return;
269 }
270
ParseLogLineData(const char * data,size_t len,T hilogInfoProto)271 template <typename T> void HilogPlugin::ParseLogLineData(const char* data, size_t len, T hilogInfoProto)
272 {
273 CHECK_NOTNULL(data, NO_RETVAL, "data is nullptr");
274 if (*data >= '0' && *data <= '9') {
275 auto* info = hilogInfoProto->add_info();
276 ParseLogLineInfo(data, len, *info);
277 info->set_id(g_id);
278 g_id++;
279 }
280 }
281
SetHilogLineDetails(const char * data,T & hilogLineInfo)282 template <typename T> bool HilogPlugin::SetHilogLineDetails(const char* data, T& hilogLineInfo)
283 {
284 char* end = nullptr;
285 struct timespec ts = {0};
286 char* pTmp = const_cast<char*>(data);
287
288 TimeStringToNS(data, &ts);
289 auto* detail = hilogLineInfo.mutable_detail();
290 detail->set_tv_sec(ts.tv_sec);
291 detail->set_tv_nsec(ts.tv_nsec);
292 pTmp = pTmp + TIME_SEC_WIDTH;
293 CHECK_TRUE(FindFirstSpace(&pTmp), false, "HilogPlugin:FindFirstSpace failed!");
294 uint32_t value = static_cast<uint32_t>(strtoul(pTmp, &end, DEC_BASE));
295 CHECK_TRUE(value > 0, false, "HilogPlugin:strtoull pid failed!");
296 detail->set_pid(value);
297 pTmp = end;
298 value = static_cast<uint32_t>(strtoul(pTmp, &end, DEC_BASE));
299 CHECK_TRUE(value > 0, false, "HilogPlugin:strtoull tid failed!");
300 detail->set_tid(value);
301 pTmp = end;
302 CHECK_TRUE(RemoveSpaces(&pTmp), false, "HilogPlugin:RemoveSpaces failed!");
303 detail->set_level(*pTmp);
304 pTmp++;
305 CHECK_TRUE(RemoveSpaces(&pTmp), false, "HilogPlugin:RemoveSpaces failed!");
306
307 if (*pTmp >= '0' && *pTmp <= '9') {
308 while (*pTmp != '/') { // 找 '/'
309 if (*pTmp == '\0' || *pTmp == '\n') {
310 return false;
311 }
312 pTmp++;
313 }
314 pTmp++;
315 end = pTmp;
316 } else if ((*pTmp >= 'a' && *pTmp <= 'z') || (*pTmp >= 'A' && *pTmp <= 'Z')) {
317 end = pTmp;
318 }
319 int index = 1;
320 if (end == nullptr) {
321 return false;
322 }
323 while (*pTmp != ':') { // 结束符 ':'
324 if (*pTmp == '\0' || *pTmp == '\n') {
325 return false;
326 }
327 pTmp++;
328 index++;
329 }
330 detail->set_tag(std::string(end, end + index - 1));
331 pTmp++;
332 CHECK_TRUE(RemoveSpaces(&pTmp), false, "HilogPlugin: RemoveSpaces failed!");
333 if (google::protobuf::internal::IsStructurallyValidUTF8(pTmp, strlen(pTmp) - 1)) {
334 hilogLineInfo.set_context(pTmp, strlen(pTmp) - 1); // - \n
335 } else {
336 PROFILER_LOG_ERROR(LOG_CORE, "HilogPlugin: log context include invalid UTF-8 data");
337 hilogLineInfo.set_context("");
338 }
339
340 return true;
341 }
342
FindFirstNum(char ** p)343 bool HilogPlugin::FindFirstNum(char** p)
344 {
345 CHECK_NOTNULL(*p, false, "HilogPlugin:%s", __func__);
346 while (**p > '9' || **p < '0') {
347 if (**p == '\0' || **p == '\n') {
348 return false;
349 }
350 (*p)++;
351 }
352 return true;
353 }
354
RemoveSpaces(char ** p)355 bool HilogPlugin::RemoveSpaces(char** p)
356 {
357 CHECK_NOTNULL(*p, false, "HilogPlugin:%s", __func__);
358 if (**p == '\0' || **p == '\n') {
359 return false;
360 }
361 while (**p == ' ') {
362 (*p)++;
363 if (**p == '\0' || **p == '\n') {
364 return false;
365 }
366 }
367 return true;
368 }
369
FindFirstSpace(char ** p)370 bool HilogPlugin::FindFirstSpace(char** p)
371 {
372 CHECK_NOTNULL(*p, false, "HilogPlugin:%s", __func__);
373 while (**p != ' ') {
374 if (**p == '\0' || **p == '\n') {
375 return false;
376 }
377 (*p)++;
378 }
379 return true;
380 }
381
StringToL(const char * word,long & value)382 bool HilogPlugin::StringToL(const char* word, long& value)
383 {
384 char* end = nullptr;
385 errno = 0;
386 value = strtol(word, &end, DEC_BASE);
387 if ((errno == ERANGE && (value == LONG_MAX)) || (errno != 0 && value == 0)) {
388 return false;
389 } else if (end == word && (*word >= '0' && *word <= '9')) {
390 return false;
391 }
392
393 return true;
394 }
395
TimeStringToNS(const char * data,struct timespec * tsTime)396 bool HilogPlugin::TimeStringToNS(const char* data, struct timespec *tsTime)
397 {
398 struct tm tmTime = {0};
399 struct tm result;
400 time_t timetTime;
401 char* end = nullptr;
402 char* pTmp = nullptr;
403 time_t nSeconds = time(nullptr);
404 uint32_t nsec = 0;
405 long fixHour = 0;
406
407 if (localtime_r(&nSeconds, &result) == nullptr) {
408 const int bufSize = 128;
409 char buf[bufSize] = { 0 };
410 strerror_r(errno, buf, bufSize);
411 PROFILER_LOG_ERROR(LOG_CORE, "HilogPlugin: get localtime failed!, errno(%d:%s)", errno, buf);
412 return false;
413 }
414 tmTime.tm_year = result.tm_year;
415 strptime(data, "%m-%d %H:%M:%S", &tmTime);
416 pTmp = const_cast<char*>(data) + TIME_HOUR_WIDTH;
417 CHECK_TRUE(StringToL(pTmp, fixHour), false, "%s:strtol fixHour failed", __func__);
418 if (static_cast<int>(fixHour) != tmTime.tm_hour) { // hours since midnight - [0, 23]
419 PROFILER_LOG_INFO(LOG_CORE, "HilogPlugin: hour(%d) <==> fix hour(%ld)!", tmTime.tm_hour, fixHour);
420 tmTime.tm_hour = fixHour;
421 }
422 pTmp = const_cast<char*>(data) + TIME_SEC_WIDTH;
423 FindFirstNum(&pTmp);
424 nsec = static_cast<uint32_t>(strtoul(pTmp, &end, DEC_BASE));
425 CHECK_TRUE(nsec > 0, false, "%s:strtoull nsec failed", __func__);
426
427 timetTime = mktime(&tmTime);
428 tsTime->tv_sec = timetTime;
429 tsTime->tv_nsec = nsec;
430
431 char buff[TIME_BUFF_LEN] = {0};
432 if (snprintf_s(buff, sizeof(buff), sizeof(buff) - 1, "%ld.%09u\n", timetTime, nsec) < 0) {
433 PROFILER_LOG_ERROR(LOG_CORE, "%s:snprintf_s error", __func__);
434 }
435 size_t buffSize = strlen(buff);
436 for (size_t i = 0; i < buffSize && protoConfig_.need_record(); i++) {
437 dataBuffer_.push_back(buff[i]);
438 }
439
440 return true;
441 }
442
GetDateTime(char * psDateTime,uint32_t size)443 int HilogPlugin::GetDateTime(char* psDateTime, uint32_t size)
444 {
445 CHECK_NOTNULL(psDateTime, -1, "HilogPlugin:%s param invalid", __func__);
446 CHECK_TRUE(size > 1, -1, "HilogPlugin:%s param invalid!", __func__);
447
448 time_t nSeconds;
449 struct tm* pTM;
450
451 nSeconds = time(nullptr);
452 pTM = localtime(&nSeconds);
453 if (pTM == nullptr) {
454 const int bufSize = 128;
455 char buf[bufSize] = { 0 };
456 strerror_r(errno, buf, bufSize);
457 PROFILER_LOG_ERROR(LOG_CORE, "HilogPlugin: get localtime failed!, errno(%d:%s)", errno, buf);
458 return -1;
459 }
460
461 if (snprintf_s(psDateTime, size, size - 1, "%04d%02d%02d%02d%02d%02d", pTM->tm_year + BASE_YEAR, pTM->tm_mon + 1,
462 pTM->tm_mday, pTM->tm_hour, pTM->tm_min, pTM->tm_sec) < 0) {
463 PROFILER_LOG_ERROR(LOG_CORE, "%s:snprintf_s error", __func__);
464 }
465
466 return 0;
467 }
468
FlushData(const T hilogLineProto)469 template <typename T> void HilogPlugin::FlushData(const T hilogLineProto)
470 {
471 protoBuffer_.resize(hilogLineProto->ByteSizeLong());
472 hilogLineProto->SerializeToArray(protoBuffer_.data(), protoBuffer_.size());
473 resultWriter_->write(resultWriter_, protoBuffer_.data(), protoBuffer_.size());
474 resultWriter_->flush(resultWriter_);
475 }
476
FlushDataOptimize(const T hilogLineProto)477 template <typename T> void HilogPlugin::FlushDataOptimize(const T hilogLineProto)
478 {
479 int messageLen = hilogLineProto->Finish();
480 resultWriter_->finishReport(resultWriter_, messageLen);
481 resultWriter_->flush(resultWriter_);
482 }