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 "event_logger.h"
16
17 #include "securec.h"
18
19 #include <cinttypes>
20 #include <list>
21 #include <map>
22 #include <regex>
23 #include <sstream>
24 #include <unistd.h>
25 #include <vector>
26 #include <iostream>
27 #include <filesystem>
28 #include <string_ex.h>
29
30 #include "parameter.h"
31
32 #include "common_utils.h"
33 #include "dfx_json_formatter.h"
34 #include "event_source.h"
35 #include "file_util.h"
36 #include "freeze_json_util.h"
37 #include "log_catcher_utils.h"
38 #include "parameter_ex.h"
39 #include "plugin_factory.h"
40 #include "string_util.h"
41 #include "sys_event.h"
42 #include "sys_event_dao.h"
43 #include "time_util.h"
44 #ifdef WINDOW_MANAGER_ENABLE
45 #include "event_focus_listener.h"
46 #include "window_manager_lite.h"
47 #include "wm_common.h"
48 #endif
49
50 #include "event_log_task.h"
51 #include "event_logger_config.h"
52
53 namespace OHOS {
54 namespace HiviewDFX {
55 REGISTER(EventLogger);
56 DEFINE_LOG_LABEL(0xD002D01, "EventLogger");
IsInterestedPipelineEvent(std::shared_ptr<Event> event)57 bool EventLogger::IsInterestedPipelineEvent(std::shared_ptr<Event> event)
58 {
59 if (event == nullptr) {
60 return false;
61 }
62 if (event->eventId_ > EVENT_MAX_ID) {
63 return false;
64 }
65
66 auto sysEvent = Event::DownCastTo<SysEvent>(event);
67 if (eventLoggerConfig_.find(sysEvent->eventName_) == eventLoggerConfig_.end()) {
68 return false;
69 }
70 HIVIEW_LOGD("event time:%{public}" PRIu64 " jsonExtraInfo is %{public}s", TimeUtil::GetMilliseconds(),
71 sysEvent->AsJsonStr().c_str());
72
73 EventLoggerConfig::EventLoggerConfigData& configOut = eventLoggerConfig_[sysEvent->eventName_];
74 sysEvent->eventName_ = configOut.name;
75 sysEvent->SetValue("eventLog_action", configOut.action);
76 sysEvent->SetValue("eventLog_interval", configOut.interval);
77 return true;
78 }
79
OnEvent(std::shared_ptr<Event> & onEvent)80 bool EventLogger::OnEvent(std::shared_ptr<Event> &onEvent)
81 {
82 if (onEvent == nullptr) {
83 HIVIEW_LOGE("event == nullptr");
84 return false;
85 }
86 #ifdef WINDOW_MANAGER_ENABLE
87 EventFocusListener::RegisterFocusListener();
88 #endif
89 auto sysEvent = Event::DownCastTo<SysEvent>(onEvent);
90
91 long pid = sysEvent->GetEventIntValue("PID") ? sysEvent->GetEventIntValue("PID") : sysEvent->GetPid();
92 std::string eventName = sysEvent->eventName_;
93 if (eventName == "GESTURE_NAVIGATION_BACK" || eventName == "FREQUENT_CLICK_WARNING") {
94 #ifdef WINDOW_MANAGER_ENABLE
95 if (EventFocusListener::registerState_ == EventFocusListener::REGISTERED) {
96 ReportUserPanicWarning(sysEvent, pid);
97 }
98 #endif
99 return true;
100 }
101 if (!IsHandleAppfreeze(sysEvent)) {
102 return true;
103 }
104
105 std::string domain = sysEvent->domain_;
106 HIVIEW_LOGI("domain=%{public}s, eventName=%{public}s, pid=%{public}ld", domain.c_str(), eventName.c_str(), pid);
107
108 if (CheckProcessRepeatFreeze(eventName, pid)) {
109 return true;
110 }
111 if (sysEvent->GetValue("eventLog_action").empty()) {
112 HIVIEW_LOGI("eventName=%{public}s, pid=%{public}ld, eventLog_action is empty.", eventName.c_str(), pid);
113 UpdateDB(sysEvent, "nolog");
114 return true;
115 }
116
117 sysEvent->OnPending();
118
119 bool isFfrt = std::find(DUMP_FFRT.begin(), DUMP_FFRT.end(), eventName) != DUMP_FFRT.end();
120 auto task = [this, sysEvent, isFfrt] {
121 HIVIEW_LOGI("time:%{public}" PRIu64 " jsonExtraInfo is %{public}s", TimeUtil::GetMilliseconds(),
122 sysEvent->AsJsonStr().c_str());
123 if (!JudgmentRateLimiting(sysEvent)) {
124 return;
125 }
126 if (isFfrt) {
127 this->StartFfrtDump(sysEvent);
128 }
129 this->StartLogCollect(sysEvent);
130 };
131 HIVIEW_LOGI("before submit event task to ffrt, eventName=%{public}s, pid=%{public}ld", eventName.c_str(), pid);
132 ffrt::submit(task, {}, {}, ffrt::task_attr().name("eventlogger"));
133 HIVIEW_LOGD("after submit event task to ffrt, eventName=%{public}s, pid=%{public}ld", eventName.c_str(), pid);
134 return true;
135 }
136
GetFile(std::shared_ptr<SysEvent> event,std::string & logFile,bool isFfrt)137 int EventLogger::GetFile(std::shared_ptr<SysEvent> event, std::string& logFile, bool isFfrt)
138 {
139 uint64_t logTime = event->happenTime_ / TimeUtil::SEC_TO_MILLISEC;
140 std::string formatTime = TimeUtil::TimestampFormatToDate(logTime, "%Y%m%d%H%M%S");
141 int32_t pid = static_cast<int32_t>(event->GetEventIntValue("PID"));
142 pid = pid ? pid : event->GetPid();
143 if (!isFfrt) {
144 std::string idStr = event->eventName_.empty() ? std::to_string(event->eventId_) : event->eventName_;
145 logFile = idStr + "-" + std::to_string(pid) + "-" + formatTime + ".log";
146 } else {
147 logFile = "ffrt_" + std::to_string(pid) + "_" + formatTime;
148 }
149
150 if (FileUtil::FileExists(LOGGER_EVENT_LOG_PATH + "/" + logFile)) {
151 HIVIEW_LOGW("filename: %{public}s is existed, direct use.", logFile.c_str());
152 if (!isFfrt) {
153 UpdateDB(event, logFile);
154 }
155 return -1;
156 }
157 return logStore_->CreateLogFile(logFile);
158 }
159
StartFfrtDump(std::shared_ptr<SysEvent> event)160 void EventLogger::StartFfrtDump(std::shared_ptr<SysEvent> event)
161 {
162 LogCatcherUtils::FFRT_TYPE type = LogCatcherUtils::TOP;
163 long pid = event->GetEventIntValue("PID") ? event->GetEventIntValue("PID") : event->GetPid();
164 #ifdef WINDOW_MANAGER_ENABLE
165 std::vector<Rosen::MainWindowInfo> windowInfos;
166 #endif
167 if (event->eventName_ == "GET_DISPLAY_SNAPSHOT" || event->eventName_ == "CREATE_VIRTUAL_SCREEN") {
168 #ifdef WINDOW_MANAGER_ENABLE
169 Rosen::WindowManagerLite::GetInstance().GetMainWindowInfos(TOP_WINDOW_NUM, windowInfos);
170 if (windowInfos.size() == 0) {
171 return;
172 }
173 #else
174 return;
175 #endif
176 } else {
177 type = LogCatcherUtils::GetFfrtDumpType(pid);
178 }
179
180 std::string ffrtFile;
181 int ffrtFd = GetFile(event, ffrtFile, true);
182 if (ffrtFd < 0) {
183 HIVIEW_LOGE("create ffrt log file %{public}s failed, %{public}d", ffrtFile.c_str(), ffrtFd);
184 return;
185 }
186
187 int count = (type == LogCatcherUtils::TOP) ? LogCatcherUtils::WAIT_CHILD_PROCESS_COUNT * DUMP_TIME_RATIO :
188 LogCatcherUtils::WAIT_CHILD_PROCESS_COUNT;
189 if (type == LogCatcherUtils::TOP) {
190 #ifdef WINDOW_MANAGER_ENABLE
191 FileUtil::SaveStringToFd(ffrtFd, "dump topWindowInfos, process infos:\n");
192 std::string cmdAms = "--ffrt ";
193 std::string cmdSam = "--ffrt ";
194 int size = static_cast<int>(windowInfos.size());
195 for (int i = 0; i < size ; i++) {
196 auto info = windowInfos[i];
197 FileUtil::SaveStringToFd(ffrtFd, " " + std::to_string(info.pid_) + ":" + info.bundleName_ + "\n");
198 cmdAms += std::to_string(info.pid_) + (i < size -1 ? "," : "");
199 cmdSam += std::to_string(info.pid_) + (i < size -1 ? "|" : "");
200 }
201 LogCatcherUtils::ReadShellToFile(ffrtFd, "ApplicationManagerService", cmdAms, count);
202 if (count > LogCatcherUtils::WAIT_CHILD_PROCESS_COUNT / DUMP_TIME_RATIO) {
203 LogCatcherUtils::ReadShellToFile(ffrtFd, "SystemAbilityManager", cmdSam, count);
204 }
205 #endif
206 } else {
207 FileUtil::SaveStringToFd(ffrtFd, "ffrt dump info:\n");
208 std::string serviceName = (type == LogCatcherUtils::APP) ? "ApplicationManagerService" : "SystemAbilityManager";
209 LogCatcherUtils::ReadShellToFile(ffrtFd, serviceName, "--ffrt " + std::to_string(pid), count);
210 }
211 close(ffrtFd);
212 }
213
CollectMemInfo(int fd,std::shared_ptr<SysEvent> event)214 void EventLogger::CollectMemInfo(int fd, std::shared_ptr<SysEvent> event)
215 {
216 std::string content = event->GetEventValue("FREEZE_MEMORY");
217 if (!content.empty()) {
218 std::vector<std::string> vec;
219 OHOS::SplitStr(content, "\\n", vec);
220 FileUtil::SaveStringToFd(fd, "\nMemoryCatcher --\n");
221 for (const std::string& mem : vec) {
222 FileUtil::SaveStringToFd(fd, mem + "\n");
223 }
224 }
225 }
226
SaveDbToFile(const std::shared_ptr<SysEvent> & event)227 void EventLogger::SaveDbToFile(const std::shared_ptr<SysEvent>& event)
228 {
229 std::string historyFile = LOGGER_EVENT_LOG_PATH + "/" + "history.log";
230 mode_t mode = 0644;
231 if (FileUtil::CreateFile(historyFile, mode) != 0 && !FileUtil::FileExists(historyFile)) {
232 HIVIEW_LOGE("failed to create file=%{public}s, errno=%{public}d", historyFile.c_str(), errno);
233 return;
234 }
235 std::vector<std::string> lines;
236 FileUtil::LoadLinesFromFile(historyFile, lines);
237 bool truncated = false;
238 if (lines.size() > HISTORY_EVENT_LIMIT) {
239 truncated = true;
240 }
241 auto time = TimeUtil::TimestampFormatToDate(event->happenTime_ / TimeUtil::SEC_TO_MILLISEC,
242 "%Y%m%d%H%M%S");
243 long pid = event->GetEventIntValue("PID") ? event->GetEventIntValue("PID") : event->GetPid();
244 long uid = event->GetEventIntValue("UID") ? event->GetEventIntValue("UID") : event->GetUid();
245 std::string str = "time[" + time + "], domain[" + event->domain_ + "], wpName[" +
246 event->eventName_ + "], pid: " + std::to_string(pid) + ", uid: " + std::to_string(uid) + "\n";
247 FileUtil::SaveStringToFile(historyFile, str, truncated);
248 }
249
StartLogCollect(std::shared_ptr<SysEvent> event)250 void EventLogger::StartLogCollect(std::shared_ptr<SysEvent> event)
251 {
252 std::string logFile;
253 int fd = GetFile(event, logFile, false);
254 if (fd < 0) {
255 HIVIEW_LOGE("create log file %{public}s failed, %{public}d", logFile.c_str(), fd);
256 return;
257 }
258
259 int jsonFd = -1;
260 if (FreezeJsonUtil::IsAppFreeze(event->eventName_)) {
261 std::string jsonFilePath = FreezeJsonUtil::GetFilePath(event->GetEventIntValue("PID"),
262 event->GetEventIntValue("UID"), event->happenTime_);
263 jsonFd = FreezeJsonUtil::GetFd(jsonFilePath);
264 }
265
266 std::unique_ptr<EventLogTask> logTask = std::make_unique<EventLogTask>(fd, jsonFd, event);
267 std::string cmdStr = event->GetValue("eventLog_action");
268 std::vector<std::string> cmdList;
269 StringUtil::SplitStr(cmdStr, ",", cmdList);
270 for (const std::string& cmd : cmdList) {
271 logTask->AddLog(cmd);
272 }
273
274 const uint32_t placeholder = 3;
275 auto start = TimeUtil::GetMilliseconds();
276 uint64_t startTime = start / TimeUtil::SEC_TO_MILLISEC;
277 std::ostringstream startTimeStr;
278 startTimeStr << "start time: " << TimeUtil::TimestampFormatToDate(startTime, "%Y/%m/%d-%H:%M:%S");
279 startTimeStr << ":" << std::setw(placeholder) << std::setfill('0') <<
280 std::to_string(start % TimeUtil::SEC_TO_MILLISEC);
281 startTimeStr << std::endl;
282 FileUtil::SaveStringToFd(fd, startTimeStr.str());
283 WriteCommonHead(fd, event);
284 WriteFreezeJsonInfo(fd, jsonFd, event);
285 CollectMemInfo(fd, event);
286 auto ret = logTask->StartCompose();
287 if (ret != EventLogTask::TASK_SUCCESS) {
288 HIVIEW_LOGE("capture fail %{public}d", ret);
289 }
290 auto end = TimeUtil::GetMilliseconds();
291 std::string totalTime = "\n\nCatcher log total time is " + std::to_string(end - start) + "ms\n";
292 FileUtil::SaveStringToFd(fd, totalTime);
293 close(fd);
294 if (jsonFd >= 0) {
295 close(jsonFd);
296 }
297 UpdateDB(event, logFile);
298 SaveDbToFile(event);
299
300 constexpr int waitTime = 1;
301 auto CheckFinishFun = [this, event] { this->CheckEventOnContinue(event); };
302 threadLoop_->AddTimerEvent(nullptr, nullptr, CheckFinishFun, waitTime, false);
303 HIVIEW_LOGI("Collect on finish, name: %{public}s", logFile.c_str());
304 }
305
ParseMsgForMessageAndEventHandler(const std::string & msg,std::string & message,std::string & eventHandlerStr)306 bool ParseMsgForMessageAndEventHandler(const std::string& msg, std::string& message, std::string& eventHandlerStr)
307 {
308 std::vector<std::string> lines;
309 StringUtil::SplitStr(msg, "\n", lines, false, true);
310 bool isGetMessage = false;
311 std::string messageStartFlag = "Fault time:";
312 std::string messageEndFlag = "mainHandler dump is:";
313 std::string eventFlag = "Event {";
314 bool isGetEvent = false;
315 std::regex eventStartFlag(".*((Immediate)|(High)|(Low)) priority event queue information:.*");
316 std::regex eventEndFlag(".*Total size of ((Immediate)|(High)|(Low)) events :.*");
317 std::list<std::string> eventHandlerList;
318 for (auto line = lines.begin(); line != lines.end(); line++) {
319 if ((*line).find(messageStartFlag) != std::string::npos) {
320 isGetMessage = true;
321 continue;
322 }
323 if (isGetMessage) {
324 if ((*line).find(messageEndFlag) != std::string::npos) {
325 isGetMessage = false;
326 HIVIEW_LOGD("Get FreezeJson message jsonStr: %{public}s", message.c_str());
327 continue;
328 }
329 message += StringUtil::TrimStr(*line);
330 continue;
331 }
332 if (regex_match(*line, eventStartFlag)) {
333 isGetEvent = true;
334 continue;
335 }
336 if (isGetEvent) {
337 if (regex_match(*line, eventEndFlag)) {
338 isGetEvent = false;
339 continue;
340 }
341 std::string::size_type pos = (*line).find(eventFlag);
342 if (pos == std::string::npos) {
343 continue;
344 }
345 std::string handlerStr = StringUtil::TrimStr(*line).substr(pos);
346 HIVIEW_LOGD("Get EventHandler str: %{public}s.", handlerStr.c_str());
347 eventHandlerList.push_back(handlerStr);
348 }
349 }
350 eventHandlerStr = FreezeJsonUtil::GetStrByList(eventHandlerList);
351 return true;
352 }
353
ParsePeerBinder(const std::string & binderInfo,std::string & binderInfoJsonStr)354 void ParsePeerBinder(const std::string& binderInfo, std::string& binderInfoJsonStr)
355 {
356 std::vector<std::string> lines;
357 StringUtil::SplitStr(binderInfo, "\\n", lines, false, true);
358 std::list<std::string> infoList;
359 std::map<std::string, std::string> processNameMap;
360
361 for (auto lineIt = lines.begin(); lineIt != lines.end(); lineIt++) {
362 std::string line = *lineIt;
363 if (line.empty() || line.find("async") != std::string::npos) {
364 continue;
365 }
366
367 if (line.find("context") != line.npos) {
368 break;
369 }
370
371 std::istringstream lineStream(line);
372 std::vector<std::string> strList;
373 std::string tmpstr;
374 while (lineStream >> tmpstr) {
375 strList.push_back(tmpstr);
376 }
377 if (strList.size() < 7) { // less than 7: valid array size
378 continue;
379 }
380 // 2: binder peer id
381 std::string pidStr = strList[2].substr(0, strList[2].find(":"));
382 if (pidStr == "") {
383 continue;
384 }
385 if (processNameMap.find(pidStr) == processNameMap.end()) {
386 std::string filePath = "/proc/" + pidStr + "/cmdline";
387 std::string realPath;
388 if (!FileUtil::PathToRealPath(filePath, realPath)) {
389 continue;
390 }
391 std::ifstream cmdLineFile(realPath);
392 std::string processName;
393 if (cmdLineFile) {
394 std::getline(cmdLineFile, processName);
395 cmdLineFile.close();
396 processName = StringUtil::FormatCmdLine(processName);
397 processNameMap[pidStr] = processName;
398 } else {
399 HIVIEW_LOGE("Fail to open /proc/%{public}s/cmdline", pidStr.c_str());
400 }
401 }
402 std::string lineStr = line + " " + pidStr + FreezeJsonUtil::WrapByParenthesis(processNameMap[pidStr]);
403 infoList.push_back(lineStr);
404 }
405 binderInfoJsonStr = FreezeJsonUtil::GetStrByList(infoList);
406 }
407
WriteCommonHead(int fd,std::shared_ptr<SysEvent> event)408 bool EventLogger::WriteCommonHead(int fd, std::shared_ptr<SysEvent> event)
409 {
410 std::ostringstream headerStream;
411
412 headerStream << "DOMAIN = " << event->domain_ << std::endl;
413 headerStream << "EVENTNAME = " << event->eventName_ << std::endl;
414 uint64_t logTime = event->happenTime_ / TimeUtil::SEC_TO_MILLISEC;
415 uint64_t logTimeMs = event->happenTime_ % TimeUtil::SEC_TO_MILLISEC;
416 std::string happenTime = TimeUtil::TimestampFormatToDate(logTime, "%Y/%m/%d-%H:%M:%S");
417 headerStream << "TIMESTAMP = " << happenTime << ":" << logTimeMs << std::endl;
418 long pid = event->GetEventIntValue("PID");
419 pid = pid ? pid : event->GetPid();
420 headerStream << "PID = " << pid << std::endl;
421 long uid = event->GetEventIntValue("UID");
422 uid = uid ? uid : event->GetUid();
423 headerStream << "UID = " << uid << std::endl;
424 if (event->GetEventIntValue("TID")) {
425 headerStream << "TID = " << event->GetEventIntValue("TID") << std::endl;
426 } else {
427 headerStream << "TID = " << pid << std::endl;
428 }
429 if (event->GetEventValue("MODULE_NAME") != "") {
430 headerStream << "MODULE_NAME = " << event->GetEventValue("MODULE_NAME") << std::endl;
431 } else {
432 headerStream << "PACKAGE_NAME = " << event->GetEventValue("PACKAGE_NAME") << std::endl;
433 }
434 headerStream << "PROCESS_NAME = " << event->GetEventValue("PROCESS_NAME") << std::endl;
435 headerStream << "eventLog_action = " << event->GetValue("eventLog_action") << std::endl;
436 headerStream << "eventLog_interval = " << event->GetValue("eventLog_interval") << std::endl;
437
438 FileUtil::SaveStringToFd(fd, headerStream.str());
439 return true;
440 }
441
WriteCallStack(std::shared_ptr<SysEvent> event,int fd)442 void EventLogger::WriteCallStack(std::shared_ptr<SysEvent> event, int fd)
443 {
444 if (event->domain_.compare("FORM_MANAGER") == 0 && event->eventName_.compare("FORM_BLOCK_CALLSTACK") == 0) {
445 std::ostringstream stackOss;
446 std::string stackMsg = StringUtil::ReplaceStr(event->GetEventValue("EVENT_KEY_FORM_BLOCK_CALLSTACK"),
447 "\\n", "\n");
448 stackOss << "CallStack = " << stackMsg << std::endl;
449 FileUtil::SaveStringToFd(fd, stackOss.str());
450
451 std::ostringstream appNameOss;
452 std::string appMsg = StringUtil::ReplaceStr(event->GetEventValue("EVENT_KEY_FORM_BLOCK_APPNAME"),
453 "\\n", "\n");
454 appNameOss << "AppName = " << appMsg << std::endl;
455 FileUtil::SaveStringToFd(fd, appNameOss.str());
456 }
457 }
458
GetAppFreezeFile(std::string & stackPath)459 std::string EventLogger::GetAppFreezeFile(std::string& stackPath)
460 {
461 std::string result = "";
462 if (!FileUtil::FileExists(stackPath)) {
463 result = "";
464 HIVIEW_LOGE("File is not exist");
465 return result;
466 }
467 FileUtil::LoadStringFromFile(stackPath, result);
468 bool isRemove = FileUtil::RemoveFile(stackPath.c_str());
469 HIVIEW_LOGI("Remove file? isRemove:%{public}d", isRemove);
470 return result;
471 }
472
IsKernelStack(const std::string & stack)473 bool EventLogger::IsKernelStack(const std::string& stack)
474 {
475 return (!stack.empty() && stack.find("Stack backtrace") != std::string::npos);
476 }
477
GetNoJsonStack(std::string & stack,std::string & contentStack,std::string & kernelStack,bool isFormat)478 void EventLogger::GetNoJsonStack(std::string& stack, std::string& contentStack,
479 std::string& kernelStack, bool isFormat)
480 {
481 if (!IsKernelStack(contentStack)) {
482 stack = contentStack;
483 contentStack = "[]";
484 } else if (DfxJsonFormatter::FormatKernelStack(contentStack, stack, isFormat)) {
485 kernelStack = contentStack;
486 contentStack = stack;
487 stack = "";
488 if (!isFormat || !DfxJsonFormatter::FormatJsonStack(contentStack, stack)) {
489 stack = contentStack;
490 }
491 } else {
492 kernelStack = contentStack;
493 stack = "Failed to format kernel stack\n";
494 contentStack = "[]";
495 }
496 }
497
GetAppFreezeStack(int jsonFd,std::shared_ptr<SysEvent> event,std::string & stack,const std::string & msg,std::string & kernelStack)498 void EventLogger::GetAppFreezeStack(int jsonFd, std::shared_ptr<SysEvent> event,
499 std::string& stack, const std::string& msg, std::string& kernelStack)
500 {
501 std::string message;
502 std::string eventHandlerStr;
503 ParseMsgForMessageAndEventHandler(msg, message, eventHandlerStr);
504 std::string appRunningUniqueId = event->GetEventValue("APP_RUNNING_UNIQUE_ID");
505
506 std::string jsonStack = event->GetEventValue("STACK");
507 HIVIEW_LOGI("Current jsonStack is? jsonStack:%{public}s", jsonStack.c_str());
508 if (FileUtil::FileExists(jsonStack)) {
509 jsonStack = GetAppFreezeFile(jsonStack);
510 }
511
512 if (!jsonStack.empty() && jsonStack[0] == '[') { // json stack info should start with '['
513 jsonStack = StringUtil::UnescapeJsonStringValue(jsonStack);
514 if (!DfxJsonFormatter::FormatJsonStack(jsonStack, stack)) {
515 stack = jsonStack;
516 }
517 } else {
518 GetNoJsonStack(stack, jsonStack, kernelStack, true);
519 }
520
521 GetFailedDumpStackMsg(stack, event);
522
523 if (jsonFd >= 0) {
524 HIVIEW_LOGI("success to open FreezeJsonFile! jsonFd: %{public}d", jsonFd);
525 FreezeJsonUtil::WriteKeyValue(jsonFd, "message", message);
526 FreezeJsonUtil::WriteKeyValue(jsonFd, "event_handler", eventHandlerStr);
527 FreezeJsonUtil::WriteKeyValue(jsonFd, "appRunningUniqueId", appRunningUniqueId);
528 FreezeJsonUtil::WriteKeyValue(jsonFd, "stack", jsonStack);
529 } else {
530 HIVIEW_LOGE("fail to open FreezeJsonFile! jsonFd: %{public}d", jsonFd);
531 }
532 }
533
WriteKernelStackToFile(std::shared_ptr<SysEvent> event,int originFd,const std::string & kernelStack)534 void EventLogger::WriteKernelStackToFile(std::shared_ptr<SysEvent> event, int originFd,
535 const std::string& kernelStack)
536 {
537 if (kernelStack.empty()) {
538 return;
539 }
540 uint64_t logTime = event->happenTime_ / TimeUtil::SEC_TO_MILLISEC;
541 std::string formatTime = TimeUtil::TimestampFormatToDate(logTime, "%Y%m%d%H%M%S");
542 int32_t pid = static_cast<int32_t>(event->GetEventIntValue("PID"));
543 pid = pid ? pid : event->GetPid();
544 std::string idStr = event->eventName_.empty() ? std::to_string(event->eventId_) : event->eventName_;
545 std::string logFile = idStr + "-" + std::to_string(pid) + "-" + formatTime + "-KernelStack-" +
546 std::to_string(originFd) + ".log";
547 std::string path = LOGGER_EVENT_LOG_PATH + "/" + logFile;
548 if (FileUtil::FileExists(path)) {
549 HIVIEW_LOGI("Filename: %{public}s is existed.", logFile.c_str());
550 return;
551 }
552 int kernelFd = logStore_->CreateLogFile(logFile);
553 if (kernelFd >= 0) {
554 FileUtil::SaveStringToFd(kernelFd, kernelStack);
555 close(kernelFd);
556 HIVIEW_LOGD("Success WriteKernelStackToFile: %{public}s.", path.c_str());
557 }
558 }
559
ParsePeerStack(std::string & binderInfo,std::string & binderPeerStack)560 void EventLogger::ParsePeerStack(std::string& binderInfo, std::string& binderPeerStack)
561 {
562 if (binderInfo.empty() || !IsKernelStack(binderInfo)) {
563 return;
564 }
565 std::string tags = "PeerBinder catcher stacktrace for pid ";
566 auto index = binderInfo.find(tags);
567 if (index == std::string::npos) {
568 return;
569 }
570 std::ostringstream oss;
571 oss << binderInfo.substr(0, index);
572 std::string bodys = binderInfo.substr(index, binderInfo.size());
573 std::vector<std::string> lines;
574 StringUtil::SplitStr(bodys, tags, lines, false, true);
575 std::string stack;
576 std::string kernelStack;
577 for (auto lineIt = lines.begin(); lineIt != lines.end(); lineIt++) {
578 std::string line = tags + *lineIt;
579 stack = "";
580 kernelStack = "";
581 GetNoJsonStack(stack, line, kernelStack, false);
582 binderPeerStack += kernelStack;
583 oss << stack << std::endl;
584 }
585 binderInfo = oss.str();
586 }
587
WriteFreezeJsonInfo(int fd,int jsonFd,std::shared_ptr<SysEvent> event)588 bool EventLogger::WriteFreezeJsonInfo(int fd, int jsonFd, std::shared_ptr<SysEvent> event)
589 {
590 std::string msg = StringUtil::ReplaceStr(event->GetEventValue("MSG"), "\\n", "\n");
591 std::string stack;
592 std::string binderInfo = event -> GetEventValue("BINDER_INFO");
593 if (FreezeJsonUtil::IsAppFreeze(event -> eventName_)) {
594 std::string kernelStack = "";
595 GetAppFreezeStack(jsonFd, event, stack, msg, kernelStack);
596 if (!binderInfo.empty() && jsonFd >= 0) {
597 HIVIEW_LOGI("Current binderInfo is? binderInfo:%{public}s", binderInfo.c_str());
598 if (FileUtil::FileExists(binderInfo)) {
599 binderInfo = GetAppFreezeFile(binderInfo);
600 }
601 std::string binderInfoJsonStr;
602 ParsePeerBinder(binderInfo, binderInfoJsonStr);
603 FreezeJsonUtil::WriteKeyValue(jsonFd, "peer_binder", binderInfoJsonStr);
604 ParsePeerStack(binderInfo, kernelStack);
605 }
606 WriteKernelStackToFile(event, fd, kernelStack);
607 } else {
608 stack = event->GetEventValue("STACK");
609 HIVIEW_LOGI("Current stack is? stack:%{public}s", stack.c_str());
610 if (FileUtil::FileExists(stack)) {
611 stack = GetAppFreezeFile(stack);
612 std::string tempStack = "";
613 std::string kernelStack = "";
614 GetNoJsonStack(tempStack, stack, kernelStack, false);
615 WriteKernelStackToFile(event, fd, kernelStack);
616 stack = tempStack;
617 }
618 GetFailedDumpStackMsg(stack, event);
619 }
620
621 std::ostringstream oss;
622 oss << "MSG = " << msg << std::endl;
623 if (!stack.empty()) {
624 oss << StringUtil::UnescapeJsonStringValue(stack) << std::endl;
625 }
626 if (!binderInfo.empty()) {
627 oss << StringUtil::UnescapeJsonStringValue(binderInfo) << std::endl;
628 }
629 FileUtil::SaveStringToFd(fd, oss.str());
630 WriteCallStack(event, fd);
631 return true;
632 }
633
GetFailedDumpStackMsg(std::string & stack,std::shared_ptr<SysEvent> event)634 void EventLogger::GetFailedDumpStackMsg(std::string& stack, std::shared_ptr<SysEvent> event)
635 {
636 std::string failedStackStart = " Failed to dump stacktrace for ";
637 if (dbHelper_ != nullptr && stack.size() >= failedStackStart.size() &&
638 !stack.compare(0, failedStackStart.size(), failedStackStart) &&
639 stack.find("syscall SIGDUMP error") != std::string::npos) {
640 long pid = event->GetEventIntValue("PID") ? event->GetEventIntValue("PID") : event->GetPid();
641 std::string packageName = event->GetEventValue("PACKAGE_NAME").empty() ?
642 event->GetEventValue("PROCESS_NAME") : event->GetEventValue("PACKAGE_NAME");
643
644 std::vector<WatchPoint> list;
645 FreezeResult freezeResult(0, "FRAMEWORK", "PROCESS_KILL");
646 freezeResult.SetSamePackage("true");
647 dbHelper_->SelectEventFromDB(event->happenTime_ - QUERY_PROCESS_KILL_INTERVAL, event->happenTime_, list,
648 packageName, freezeResult);
649
650 std::string appendStack = "";
651 for (auto watchPoint : list) {
652 if (watchPoint.GetPid() == pid) {
653 appendStack += "\n" + watchPoint.GetMsg();
654 }
655 }
656 stack += appendStack.empty() ? "\ncan not get process kill reason" : "\nprocess may be killed by : "
657 + appendStack;
658 }
659 }
660
JudgmentRateLimiting(std::shared_ptr<SysEvent> event)661 bool EventLogger::JudgmentRateLimiting(std::shared_ptr<SysEvent> event)
662 {
663 int32_t interval = event->GetIntValue("eventLog_interval");
664 if (interval == 0) {
665 return true;
666 }
667
668 int64_t pid = event->GetEventIntValue("PID");
669 pid = pid ? pid : event->GetPid();
670 std::string eventName = event->eventName_;
671 std::string eventPid = std::to_string(pid);
672
673 intervalMutex_.lock();
674 std::time_t now = std::time(0);
675 for (auto it = eventTagTime_.begin(); it != eventTagTime_.end();) {
676 if (it->first.find(eventName) != it->first.npos) {
677 if ((now - it->second) >= interval) {
678 it = eventTagTime_.erase(it);
679 continue;
680 }
681 }
682 ++it;
683 }
684
685 std::string tagTimeName = eventName + eventPid;
686 auto it = eventTagTime_.find(tagTimeName);
687 if (it != eventTagTime_.end()) {
688 if ((now - it->second) < interval) {
689 HIVIEW_LOGE("event: id:0x%{public}d, eventName:%{public}s pid:%{public}s. \
690 interval:%{public}" PRId32 " There's not enough interval",
691 event->eventId_, eventName.c_str(), eventPid.c_str(), interval);
692 intervalMutex_.unlock();
693 return false;
694 }
695 }
696 eventTagTime_[tagTimeName] = now;
697 HIVIEW_LOGD("event: id:0x%{public}d, eventName:%{public}s pid:%{public}s. \
698 interval:%{public}" PRId32 " normal interval",
699 event->eventId_, eventName.c_str(), eventPid.c_str(), interval);
700 intervalMutex_.unlock();
701 return true;
702 }
703
UpdateDB(std::shared_ptr<SysEvent> event,std::string logFile)704 bool EventLogger::UpdateDB(std::shared_ptr<SysEvent> event, std::string logFile)
705 {
706 if (logFile == "nolog") {
707 HIVIEW_LOGI("set info_ with nolog into db.");
708 event->SetEventValue(EventStore::EventCol::INFO, "nolog", false);
709 } else {
710 auto logPath = R"~(logPath:)~" + LOGGER_EVENT_LOG_PATH + "/" + logFile;
711 event->SetEventValue(EventStore::EventCol::INFO, logPath, true);
712 }
713 return true;
714 }
715
IsHandleAppfreeze(std::shared_ptr<SysEvent> event)716 bool EventLogger::IsHandleAppfreeze(std::shared_ptr<SysEvent> event)
717 {
718 std::string bundleName = event->GetEventValue("PACKAGE_NAME");
719 if (bundleName.empty()) {
720 bundleName = event->GetEventValue("MODULE_NAME");
721 }
722 if (bundleName.empty()) {
723 return true;
724 }
725
726 const int buffSize = 128;
727 char paramOutBuff[buffSize] = {0};
728 GetParameter("hiviewdfx.appfreeze.filter_bundle_name", "", paramOutBuff, buffSize - 1);
729
730 std::string str(paramOutBuff);
731 if (str.find(bundleName) != std::string::npos) {
732 HIVIEW_LOGW("appfreeze filtration %{public}s.", bundleName.c_str());
733 return false;
734 }
735 return true;
736 }
737
738 #ifdef WINDOW_MANAGER_ENABLE
ReportUserPanicWarning(std::shared_ptr<SysEvent> event,long pid)739 void EventLogger::ReportUserPanicWarning(std::shared_ptr<SysEvent> event, long pid)
740 {
741 if (event->eventName_ == "FREQUENT_CLICK_WARNING") {
742 if (event->happenTime_ - EventFocusListener::lastChangedTime_ <= CLICK_FREEZE_TIME_LIMIT) {
743 return;
744 }
745 } else {
746 backTimes_.push_back(event->happenTime_);
747 if (backTimes_.size() < BACK_FREEZE_COUNT_LIMIT) {
748 return;
749 }
750 if ((event->happenTime_ - backTimes_[0] <= BACK_FREEZE_TIME_LIMIT) &&
751 (event->happenTime_ - EventFocusListener::lastChangedTime_ > BACK_FREEZE_TIME_LIMIT)) {
752 backTimes_.clear();
753 } else {
754 backTimes_.erase(backTimes_.begin(), backTimes_.end() - (BACK_FREEZE_COUNT_LIMIT - 1));
755 return;
756 }
757 }
758
759 auto userPanicEvent = std::make_shared<SysEvent>("EventLogger", nullptr, "");
760
761 std::string processName = (event->eventName_ == "FREQUENT_CLICK_WARNING") ? event->GetEventValue("PROCESS_NAME") :
762 event->GetEventValue("PNAMEID");
763 std::string msg = (event->eventName_ == "FREQUENT_CLICK_WARNING") ? "frequent click" : "gesture navigation back";
764
765 userPanicEvent->domain_ = "FRAMEWORK";
766 userPanicEvent->eventName_ = "USER_PANIC_WARNING";
767 userPanicEvent->happenTime_ = TimeUtil::GetMilliseconds();
768 userPanicEvent->messageType_ = Event::MessageType::SYS_EVENT;
769 userPanicEvent->SetEventValue(EventStore::EventCol::DOMAIN, "FRAMEWORK");
770 userPanicEvent->SetEventValue(EventStore::EventCol::NAME, "USER_PANIC_WARNING");
771 userPanicEvent->SetEventValue(EventStore::EventCol::TYPE, 1);
772 userPanicEvent->SetEventValue(EventStore::EventCol::TS, TimeUtil::GetMilliseconds());
773 userPanicEvent->SetEventValue(EventStore::EventCol::TZ, TimeUtil::GetTimeZone());
774 userPanicEvent->SetEventValue("PID", pid);
775 userPanicEvent->SetEventValue("UID", 0);
776 userPanicEvent->SetEventValue("PACKAGE_NAME", processName);
777 userPanicEvent->SetEventValue("PROCESS_NAME", processName);
778 userPanicEvent->SetEventValue("MSG", msg);
779 userPanicEvent->SetPrivacy(USER_PANIC_WARNING_PRIVACY);
780 userPanicEvent->SetLevel("CRITICAL");
781 userPanicEvent->SetTag("STABILITY");
782
783 auto context = GetHiviewContext();
784 if (context != nullptr) {
785 auto seq = context->GetPipelineSequenceByName("EventloggerPipeline");
786 userPanicEvent->SetPipelineInfo("EventloggerPipeline", seq);
787 userPanicEvent->OnContinue();
788 }
789 }
790 #endif
791
CheckProcessRepeatFreeze(const std::string & eventName,long pid)792 bool EventLogger::CheckProcessRepeatFreeze(const std::string& eventName, long pid)
793 {
794 if (eventName == "THREAD_BLOCK_6S" || eventName == "APP_INPUT_BLOCK") {
795 long lastPid = lastPid_;
796 std::string lastEventName = lastEventName_;
797 lastPid_ = pid;
798 lastEventName_ = eventName;
799 if (lastPid == pid) {
800 HIVIEW_LOGI("eventName=%{public}s, pid=%{public}ld has happened", lastEventName.c_str(), pid);
801 return true;
802 }
803 }
804 return false;
805 }
806
CheckEventOnContinue(std::shared_ptr<SysEvent> event)807 void EventLogger::CheckEventOnContinue(std::shared_ptr<SysEvent> event)
808 {
809 event->ResetPendingStatus();
810 event->OnContinue();
811 }
812
OnLoad()813 void EventLogger::OnLoad()
814 {
815 HIVIEW_LOGI("EventLogger OnLoad.");
816 SetName("EventLogger");
817 SetVersion("1.0");
818 logStore_->SetMaxSize(MAX_FOLDER_SIZE);
819 logStore_->SetMinKeepingFileNumber(MAX_FILE_NUM);
820 LogStoreEx::LogFileComparator comparator = [this](const LogFile &lhs, const LogFile &rhs) {
821 return rhs < lhs;
822 };
823 logStore_->SetLogFileComparator(comparator);
824 logStore_->Init();
825 threadLoop_ = GetWorkLoop();
826
827 EventLoggerConfig logConfig;
828 eventLoggerConfig_ = logConfig.GetConfig();
829
830 activeKeyEvent_ = std::make_unique<ActiveKeyEvent>();
831 activeKeyEvent_ ->Init(logStore_);
832 FreezeCommon freezeCommon;
833 if (!freezeCommon.Init()) {
834 HIVIEW_LOGE("FreezeCommon filed.");
835 return;
836 }
837
838 std::set<std::string> freezeeventNames = freezeCommon.GetPrincipalStringIds();
839 std::unordered_set<std::string> eventNames;
840 for (auto& i : freezeeventNames) {
841 eventNames.insert(i);
842 }
843 auto context = GetHiviewContext();
844 if (context != nullptr) {
845 auto plugin = context->GetPluginByName("FreezeDetectorPlugin");
846 HIVIEW_LOGE("plugin plugin %{public}s.", plugin->GetName().c_str());
847 context->AddDispatchInfo(plugin, {}, eventNames, {}, {});
848
849 auto ptr = std::static_pointer_cast<EventLogger>(shared_from_this());
850 context->RegisterUnorderedEventListener(ptr);
851 AddListenerInfo(Event::MessageType::PLUGIN_MAINTENANCE);
852 }
853
854 GetCmdlineContent();
855 GetRebootReasonConfig();
856
857 freezeCommon_ = std::make_shared<FreezeCommon>();
858 if (freezeCommon_->Init() && freezeCommon_ != nullptr && freezeCommon_->GetFreezeRuleCluster() != nullptr) {
859 dbHelper_ = std::make_unique<DBHelper>(freezeCommon_);
860 }
861 }
862
OnUnload()863 void EventLogger::OnUnload()
864 {
865 HIVIEW_LOGD("called");
866 #ifdef WINDOW_MANAGER_ENABLE
867 EventFocusListener::UnRegisterFocusListener();
868 #endif
869 }
870
GetListenerName()871 std::string EventLogger::GetListenerName()
872 {
873 return "EventLogger";
874 }
875
OnUnorderedEvent(const Event & msg)876 void EventLogger::OnUnorderedEvent(const Event& msg)
877 {
878 if (CanProcessRebootEvent(msg)) {
879 auto task = [this] { this->ProcessRebootEvent(); };
880 threadLoop_->AddEvent(nullptr, nullptr, task);
881 }
882 }
883
CanProcessRebootEvent(const Event & event)884 bool EventLogger::CanProcessRebootEvent(const Event& event)
885 {
886 return (event.messageType_ == Event::MessageType::PLUGIN_MAINTENANCE) &&
887 (event.eventId_ == Event::EventId::PLUGIN_LOADED);
888 }
889
ProcessRebootEvent()890 void EventLogger::ProcessRebootEvent()
891 {
892 if (GetRebootReason() != LONG_PRESS) {
893 return;
894 }
895
896 auto event = std::make_shared<SysEvent>("EventLogger", nullptr, "");
897
898 if (event == nullptr) {
899 HIVIEW_LOGW("event is null.");
900 return;
901 }
902
903 event->domain_ = DOMAIN_LONGPRESS;
904 event->eventName_ = STRINGID_LONGPRESS;
905 event->happenTime_ = TimeUtil::GetMilliseconds();
906 event->messageType_ = Event::MessageType::SYS_EVENT;
907 event->SetEventValue(EventStore::EventCol::DOMAIN, DOMAIN_LONGPRESS);
908 event->SetEventValue(EventStore::EventCol::NAME, STRINGID_LONGPRESS);
909 event->SetEventValue(EventStore::EventCol::TYPE, 1);
910 event->SetEventValue(EventStore::EventCol::TS, TimeUtil::GetMilliseconds());
911 event->SetEventValue(EventStore::EventCol::TZ, TimeUtil::GetTimeZone());
912 event->SetEventValue("PID", 0);
913 event->SetEventValue("UID", 0);
914 event->SetEventValue("PACKAGE_NAME", STRINGID_LONGPRESS);
915 event->SetEventValue("PROCESS_NAME", STRINGID_LONGPRESS);
916 event->SetEventValue("MSG", STRINGID_LONGPRESS);
917 event->SetPrivacy(LONGPRESS_PRIVACY);
918 event->SetLevel(LONGPRESS_LEVEL);
919
920 auto context = GetHiviewContext();
921 if (context != nullptr) {
922 auto seq = context->GetPipelineSequenceByName("EventloggerPipeline");
923 event->SetPipelineInfo("EventloggerPipeline", seq);
924 event->OnContinue();
925 }
926 }
927
GetRebootReason() const928 std::string EventLogger::GetRebootReason() const
929 {
930 std::string reboot = "";
931 std::string reset = "";
932 if (GetMatchString(cmdlineContent_, reboot, REBOOT_REASON + PATTERN_WITHOUT_SPACE) &&
933 GetMatchString(cmdlineContent_, reset, NORMAL_RESET_TYPE + PATTERN_WITHOUT_SPACE)) {
934 if (std::any_of(rebootReasons_.begin(), rebootReasons_.end(), [&reboot, &reset](auto& reason) {
935 return (reason == reboot || reason == reset);
936 })) {
937 HIVIEW_LOGI("get reboot reason: LONG_PRESS.");
938 return LONG_PRESS;
939 }
940 }
941 return "";
942 }
943
GetCmdlineContent()944 void EventLogger::GetCmdlineContent()
945 {
946 if (FileUtil::LoadStringFromFile(cmdlinePath_, cmdlineContent_) == false) {
947 HIVIEW_LOGE("failed to read cmdline:%{public}s.", cmdlinePath_.c_str());
948 }
949 }
950
GetRebootReasonConfig()951 void EventLogger::GetRebootReasonConfig()
952 {
953 rebootReasons_.clear();
954 if (rebootReasons_.size() == 0) {
955 rebootReasons_.push_back(AP_S_PRESS6S);
956 }
957 }
958
GetMatchString(const std::string & src,std::string & dst,const std::string & pattern) const959 bool EventLogger::GetMatchString(const std::string& src, std::string& dst, const std::string& pattern) const
960 {
961 std::regex reg(pattern);
962 std::smatch result;
963 if (std::regex_search(src, result, reg)) {
964 dst = StringUtil::TrimStr(result[1], '\n');
965 return true;
966 }
967 return false;
968 }
969 } // namespace HiviewDFX
970 } // namespace OHOS
971