1 /*
2 * Copyright (c) 2024 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 "app_trace_context.h"
16
17 #include <cinttypes>
18 #include <memory>
19 #include <mutex>
20
21 #include "app_caller_event.h"
22 #include "collect_event.h"
23 #include "event_publish.h"
24 #include "file_util.h"
25 #include "hisysevent.h"
26 #include "hiview_logger.h"
27 #include "json/json.h"
28 #include "time_util.h"
29 #include "trace_flow_controller.h"
30 #include "trace_manager.h"
31 #include "utility/trace_collector.h"
32
33 namespace OHOS {
34 namespace HiviewDFX {
35 DEFINE_LOG_TAG("HiView-AppTrace");
36 namespace {
37 std::recursive_mutex g_traceMutex;
38 // start => dump, start => stop, dump => stop, stop -> start
39 constexpr int32_t TRACE_STATE_START_APP_TRACE = 1;
40 constexpr int32_t TRACE_STATE_DUMP_APP_TRACE = 2;
41 constexpr int32_t TRACE_STATE_STOP_APP_TRACE = 3;
42 constexpr int32_t DURATION_TRACE = 10; // unit second
43 const std::string UNIFIED_SHARE_PATH = "/data/log/hiview/unified_collection/trace/share/";
44
InnerMakeTraceFileName(std::shared_ptr<AppCallerEvent> appCallerEvent)45 std::string InnerMakeTraceFileName(std::shared_ptr<AppCallerEvent> appCallerEvent)
46 {
47 std::string &bundleName = appCallerEvent->bundleName_;
48 int32_t pid = appCallerEvent->pid_;
49 int64_t beginTime = appCallerEvent->taskBeginTime_;
50 int64_t endTime = appCallerEvent->taskEndTime_;
51 int32_t costTime = (appCallerEvent->taskEndTime_ - appCallerEvent->taskBeginTime_);
52
53 std::string d1 = TimeUtil::TimestampFormatToDate(beginTime/ TimeUtil::SEC_TO_MILLISEC, "%Y%m%d%H%M%S");
54 std::string d2 = TimeUtil::TimestampFormatToDate(endTime/ TimeUtil::SEC_TO_MILLISEC, "%Y%m%d%H%M%S");
55
56 std::string name;
57 name.append(UNIFIED_SHARE_PATH).append("APP_").append(bundleName).append("_").append(std::to_string(pid));
58 name.append("_").append(d1).append("_").append(d2).append("_").append(std::to_string(costTime)).append(".sys");
59 return name;
60 }
61
InnerStartAppTrace(std::shared_ptr<AppCallerEvent> appCallerEvent,bool & isOpenTrace,bool & isTraceOn)62 bool InnerStartAppTrace(std::shared_ptr<AppCallerEvent> appCallerEvent, bool &isOpenTrace, bool &isTraceOn)
63 {
64 TraceManager manager;
65 std::string appArgs = "tags:graphic,ace,app clockType:boot bufferSize:1024 overwrite:1 fileLimit:20 ";
66 appArgs.append("appPid:").append(std::to_string(appCallerEvent->pid_));
67 int32_t retCode = manager.OpenRecordingTrace(appArgs);
68 if (retCode != UCollect::UcError::SUCCESS) {
69 HIVIEW_LOGE("failed to open trace for uid=%{public}d, pid=%{public}d, error code %{public}d",
70 appCallerEvent->uid_, appCallerEvent->pid_, retCode);
71 appCallerEvent->resultCode_ = retCode;
72 return false;
73 }
74 isOpenTrace = true;
75
76 std::shared_ptr<UCollectUtil::TraceCollector> traceCollector = UCollectUtil::TraceCollector::Create();
77 CollectResult<int32_t> result = traceCollector->TraceOn();
78 if (result.retCode != UCollect::UcError::SUCCESS) {
79 HIVIEW_LOGE("failed to traceon for uid=%{public}d, pid=%{public}d, error code %{public}d",
80 appCallerEvent->uid_, appCallerEvent->pid_, retCode);
81 appCallerEvent->resultCode_ = result.retCode;
82 return false;
83 }
84 isTraceOn = true;
85 return true;
86 }
87
InnerDumpAppTrace(std::shared_ptr<AppCallerEvent> appCallerEvent,bool & isDumpTrace,bool & isTraceOn)88 void InnerDumpAppTrace(std::shared_ptr<AppCallerEvent> appCallerEvent, bool &isDumpTrace, bool &isTraceOn)
89 {
90 std::shared_ptr<UCollectUtil::TraceCollector> traceCollector = UCollectUtil::TraceCollector::Create();
91 CollectResult<std::vector<std::string>> result = traceCollector->TraceOff();
92 if (result.retCode != UCollect::UcError::SUCCESS) {
93 HIVIEW_LOGE("trace off for uid=%{public}d pid=%{public}d error code=%{public}d",
94 appCallerEvent->uid_, appCallerEvent->pid_, result.retCode);
95 appCallerEvent->resultCode_ = result.retCode;
96 return;
97 }
98
99 isTraceOn = false;
100 appCallerEvent->taskEndTime_ = static_cast<int64_t>(TimeUtil::GetMilliseconds());
101 if (result.data.empty()) {
102 HIVIEW_LOGE("failed to collect app trace for uid=%{public}d pid=%{public}d",
103 appCallerEvent->uid_, appCallerEvent->pid_);
104 } else {
105 isDumpTrace = true;
106 std::string traceFileName = InnerMakeTraceFileName(appCallerEvent);
107 FileUtil::RenameFile(result.data[0], traceFileName);
108 appCallerEvent->externalLog_ = traceFileName;
109 }
110 }
111
InnerShareAppEvent(std::shared_ptr<AppCallerEvent> appCallerEvent)112 void InnerShareAppEvent(std::shared_ptr<AppCallerEvent> appCallerEvent)
113 {
114 Json::Value eventJson;
115 eventJson[UCollectUtil::APP_EVENT_PARAM_UID] = appCallerEvent->uid_;
116 eventJson[UCollectUtil::APP_EVENT_PARAM_PID] = appCallerEvent->pid_;
117 eventJson[UCollectUtil::APP_EVENT_PARAM_TIME] = appCallerEvent->happenTime_;
118 eventJson[UCollectUtil::APP_EVENT_PARAM_BUNDLE_NAME] = appCallerEvent->bundleName_;
119 eventJson[UCollectUtil::APP_EVENT_PARAM_BUNDLE_VERSION] = appCallerEvent->bundleVersion_;
120 eventJson[UCollectUtil::APP_EVENT_PARAM_BEGIN_TIME] = appCallerEvent->beginTime_;
121 eventJson[UCollectUtil::APP_EVENT_PARAM_END_TIME] = appCallerEvent->endTime_;
122 if (appCallerEvent->isBusinessJank_) {
123 eventJson[UCollectUtil::APP_EVENT_PARAM_ISBUSINESSJANK] = appCallerEvent->isBusinessJank_;
124 }
125 Json::Value externalLog;
126 externalLog.append(appCallerEvent->externalLog_);
127 eventJson[UCollectUtil::APP_EVENT_PARAM_EXTERNAL_LOG] = externalLog;
128 std::string param = Json::FastWriter().write(eventJson);
129
130 HIVIEW_LOGI("send for uid=%{public}d pid=%{public}d", appCallerEvent->uid_, appCallerEvent->pid_);
131 EventPublish::GetInstance().PushEvent(appCallerEvent->uid_, UCollectUtil::MAIN_THREAD_JANK,
132 HiSysEvent::EventType::FAULT, param);
133 }
134
InnerReportMainThreadJankForTrace(std::shared_ptr<AppCallerEvent> appCallerEvent)135 void InnerReportMainThreadJankForTrace(std::shared_ptr<AppCallerEvent> appCallerEvent)
136 {
137 HiSysEventWrite(HiSysEvent::Domain::FRAMEWORK, UCollectUtil::MAIN_THREAD_JANK, HiSysEvent::EventType::FAULT,
138 UCollectUtil::SYS_EVENT_PARAM_BUNDLE_NAME, appCallerEvent->bundleName_,
139 UCollectUtil::SYS_EVENT_PARAM_BUNDLE_VERSION, appCallerEvent->bundleVersion_,
140 UCollectUtil::SYS_EVENT_PARAM_BEGIN_TIME, appCallerEvent->beginTime_,
141 UCollectUtil::SYS_EVENT_PARAM_END_TIME, appCallerEvent->endTime_,
142 UCollectUtil::SYS_EVENT_PARAM_THREAD_NAME, appCallerEvent->threadName_,
143 UCollectUtil::SYS_EVENT_PARAM_FOREGROUND, appCallerEvent->foreground_,
144 UCollectUtil::SYS_EVENT_PARAM_LOG_TIME, appCallerEvent->taskEndTime_,
145 UCollectUtil::SYS_EVENT_PARAM_JANK_LEVEL, 1); // 1: over 450ms
146 }
147
InnerHasCallAppTrace(std::shared_ptr<AppCallerEvent> appCallerEvent)148 bool InnerHasCallAppTrace(std::shared_ptr<AppCallerEvent> appCallerEvent)
149 {
150 std::shared_ptr<TraceFlowController> traceController = std::make_shared<TraceFlowController>();
151 if (traceController->HasCallOnceToday(appCallerEvent->uid_, appCallerEvent->happenTime_)) {
152 HIVIEW_LOGE("already capture trace uid=%{public}d pid=%{public}d",
153 appCallerEvent->uid_, appCallerEvent->pid_);
154 appCallerEvent->resultCode_ = UCollect::UcError::HAD_CAPTURED_TRACE;
155 return true;
156 }
157 return false;
158 }
159 }
160
AppTraceContext(std::shared_ptr<AppTraceState> state)161 AppTraceContext::AppTraceContext(std::shared_ptr<AppTraceState> state)
162 : pid_(0), traceBegin_(0), isOpenTrace_(false), isTraceOn_(false), isDumpTrace_(false), state_(state)
163 {}
164
TransferTo(std::shared_ptr<AppTraceState> state)165 int32_t AppTraceContext::TransferTo(std::shared_ptr<AppTraceState> state)
166 {
167 std::lock_guard<std::recursive_mutex> guard(g_traceMutex);
168 if (state_ == nullptr) {
169 state_ = state;
170 return state_->CaptureTrace();
171 }
172
173 if (!state->Accept(state_)) {
174 return -1;
175 }
176
177 state_ = state;
178 return state_->CaptureTrace();
179 }
180
PublishStackEvent(SysEvent & sysEvent)181 void AppTraceContext::PublishStackEvent(SysEvent& sysEvent)
182 {
183 if (sysEvent.GetEventIntValue(UCollectUtil::SYS_EVENT_PARAM_JANK_LEVEL) <
184 UCollectUtil::SYS_EVENT_JANK_LEVEL_VALUE_TRACE) {
185 // hicollie capture stack in application process, only need to share app event to application by hiview
186 Json::Value eventJson;
187 eventJson[UCollectUtil::APP_EVENT_PARAM_UID] = sysEvent.GetUid();
188 eventJson[UCollectUtil::APP_EVENT_PARAM_PID] = sysEvent.GetPid();
189 eventJson[UCollectUtil::APP_EVENT_PARAM_TIME] = sysEvent.happenTime_;
190 eventJson[UCollectUtil::APP_EVENT_PARAM_BUNDLE_NAME] = sysEvent.GetEventValue(
191 UCollectUtil::SYS_EVENT_PARAM_BUNDLE_NAME);
192 eventJson[UCollectUtil::APP_EVENT_PARAM_BUNDLE_VERSION] = sysEvent.GetEventValue(
193 UCollectUtil::SYS_EVENT_PARAM_BUNDLE_VERSION);
194 eventJson[UCollectUtil::APP_EVENT_PARAM_BEGIN_TIME] = sysEvent.GetEventIntValue(
195 UCollectUtil::SYS_EVENT_PARAM_BEGIN_TIME);
196 eventJson[UCollectUtil::APP_EVENT_PARAM_END_TIME] = sysEvent.GetEventIntValue(
197 UCollectUtil::SYS_EVENT_PARAM_END_TIME);
198 Json::Value externalLog;
199 externalLog.append(sysEvent.GetEventValue(UCollectUtil::SYS_EVENT_PARAM_EXTERNAL_LOG));
200 eventJson[UCollectUtil::APP_EVENT_PARAM_EXTERNAL_LOG] = externalLog;
201 std::string param = Json::FastWriter().write(eventJson);
202
203 HIVIEW_LOGI("send as stack trigger for uid=%{public}d pid=%{public}d", sysEvent.GetUid(), sysEvent.GetPid());
204 EventPublish::GetInstance().PushEvent(sysEvent.GetUid(), UCollectUtil::MAIN_THREAD_JANK,
205 HiSysEvent::EventType::FAULT, param);
206 }
207 }
208
Reset()209 void AppTraceContext::Reset()
210 {
211 pid_ = 0;
212 traceBegin_ = 0;
213 isOpenTrace_ = false;
214 isTraceOn_ = false;
215 isDumpTrace_ = false;
216 }
217
Accept(std::shared_ptr<AppTraceState> preState)218 bool StartTraceState::Accept(std::shared_ptr<AppTraceState> preState)
219 {
220 // stop -> start
221 if (preState->GetState() == TRACE_STATE_STOP_APP_TRACE) {
222 return true;
223 }
224
225 appCallerEvent_->resultCode_ = UCollect::UcError::INVALID_TRACE_STATE;
226 return false;
227 }
228
GetState()229 int32_t StartTraceState::GetState()
230 {
231 return TRACE_STATE_START_APP_TRACE;
232 }
233
CaptureTrace()234 int32_t StartTraceState::CaptureTrace()
235 {
236 int32_t retCode = DoCaptureTrace();
237
238 appCallerEvent_->eventName_ = UCollectUtil::STOP_APP_TRACE;
239 if (retCode == 0) {
240 // start -> stop after DURATION_TRACE seconds
241 plugin_->DelayProcessEvent(appCallerEvent_, DURATION_TRACE);
242 } else {
243 // start -> stop right now as start trace fail
244 // need to change to stop state then can wait for next start
245 appTraceContext_->TransferTo(std::make_shared<StopTraceState>(appTraceContext_, appCallerEvent_));
246 }
247
248 return retCode;
249 }
250
DoCaptureTrace()251 int32_t StartTraceState::DoCaptureTrace()
252 {
253 if (AppCallerEvent::isDynamicTraceOpen_) {
254 HIVIEW_LOGE("start trace is already open uid=%{public}d, pid=%{public}d",
255 appCallerEvent_->uid_, appCallerEvent_->pid_);
256 appCallerEvent_->resultCode_ = UCollect::UcError::EXISTS_CAPTURE_TASK;
257 return -1;
258 }
259
260 // app only has one trace file each day
261 if (InnerHasCallAppTrace(appCallerEvent_)) {
262 return -1;
263 }
264
265 AppCallerEvent::isDynamicTraceOpen_ = true;
266 HIVIEW_LOGI("start trace serval seconds for uid=%{public}d pid=%{public}d",
267 appCallerEvent_->uid_, appCallerEvent_->pid_);
268
269 if (!InnerStartAppTrace(appCallerEvent_, appTraceContext_->isOpenTrace_, appTraceContext_->isTraceOn_)) {
270 return -1;
271 }
272
273 appTraceContext_->traceBegin_ = static_cast<int64_t>(TimeUtil::GetMilliseconds());
274 appCallerEvent_->resultCode_ = UCollect::UcError::SUCCESS;
275 int64_t delay = appCallerEvent_->taskBeginTime_ - static_cast<int64_t>(appCallerEvent_->happenTime_);
276 int64_t cost = appTraceContext_->traceBegin_ - static_cast<int64_t>(appCallerEvent_->happenTime_);
277 HIVIEW_LOGI("trace is start for uid=%{public}d pid=%{public}d delay=%{public}" PRId64 ", cost=%{public}" PRId64 "",
278 appCallerEvent_->uid_, appCallerEvent_->pid_, delay, cost);
279 return 0;
280 }
281
Accept(std::shared_ptr<AppTraceState> preState)282 bool DumpTraceState::Accept(std::shared_ptr<AppTraceState> preState)
283 {
284 // start -> dump
285 if (preState->GetState() == TRACE_STATE_START_APP_TRACE) {
286 if (preState->appCallerEvent_->pid_ != appCallerEvent_->pid_) {
287 appCallerEvent_->resultCode_ = UCollect::UcError::INCONSISTENT_PROCESS;
288 return false;
289 }
290 return true;
291 }
292
293 appCallerEvent_->resultCode_ = UCollect::UcError::INVALID_TRACE_STATE;
294 return false;
295 }
296
GetState()297 int32_t DumpTraceState::GetState()
298 {
299 return TRACE_STATE_DUMP_APP_TRACE;
300 }
301
CaptureTrace()302 int32_t DumpTraceState::CaptureTrace()
303 {
304 int32_t retCode = DoCaptureTrace();
305
306 // dump -> stop right now
307 appCallerEvent_->eventName_ = UCollectUtil::STOP_APP_TRACE;
308 appTraceContext_->TransferTo(std::make_shared<StopTraceState>(appTraceContext_, appCallerEvent_));
309 return retCode;
310 }
311
DoCaptureTrace()312 int32_t DumpTraceState::DoCaptureTrace()
313 {
314 if (!AppCallerEvent::isDynamicTraceOpen_) {
315 HIVIEW_LOGE("dump trace is not open uid=%{public}d, pid=%{public}d",
316 appCallerEvent_->uid_, appCallerEvent_->pid_);
317 appCallerEvent_->resultCode_ = UCollect::UcError::UNEXISTS_CAPTURE_TASK;
318 return -1;
319 }
320
321 // app only has one trace file each day
322 if (InnerHasCallAppTrace(appCallerEvent_)) {
323 return -1;
324 }
325
326 int64_t delay = appCallerEvent_->taskBeginTime_ - static_cast<int64_t>(appCallerEvent_->happenTime_);
327 appCallerEvent_->taskBeginTime_ = appTraceContext_->traceBegin_;
328 InnerDumpAppTrace(appCallerEvent_, appTraceContext_->isDumpTrace_, appTraceContext_->isTraceOn_);
329
330 // hicollie capture stack in application process, only need to share app event to application by hiview
331 InnerShareAppEvent(appCallerEvent_);
332
333 std::shared_ptr<TraceFlowController> traceController = std::make_shared<TraceFlowController>();
334 traceController->RecordCaller(appCallerEvent_);
335 traceController->CleanOldAppTrace();
336
337 InnerReportMainThreadJankForTrace(appCallerEvent_);
338
339 int64_t cost = appCallerEvent_->taskEndTime_ - static_cast<int64_t>(appCallerEvent_->happenTime_);
340 HIVIEW_LOGI("dump trace for uid=%{public}d pid=%{public}d delay=%{public}" PRId64 ", cost=%{public}" PRId64 "",
341 appCallerEvent_->uid_, appCallerEvent_->pid_, delay, cost);
342 return 0;
343 }
344
Accept(std::shared_ptr<AppTraceState> preState)345 bool StopTraceState::Accept(std::shared_ptr<AppTraceState> preState)
346 {
347 // start -> stop
348 if (preState->GetState() == TRACE_STATE_START_APP_TRACE) {
349 return true;
350 }
351
352 // dump -> stop
353 if (preState->GetState() == TRACE_STATE_DUMP_APP_TRACE) {
354 return true;
355 }
356
357 HIVIEW_LOGI("already stop for uid=%{public}d pid=%{public}d", appCallerEvent_->uid_, appCallerEvent_->pid_);
358 return false;
359 }
360
GetState()361 int32_t StopTraceState::GetState()
362 {
363 return TRACE_STATE_STOP_APP_TRACE;
364 }
365
366
CaptureTrace()367 int32_t StopTraceState::CaptureTrace()
368 {
369 if (appTraceContext_ == nullptr || appCallerEvent_ == nullptr) {
370 HIVIEW_LOGI("does not init state, can not run");
371 return -1;
372 }
373
374 int32_t retCode = DoCaptureTrace();
375 appTraceContext_->Reset();
376 AppCallerEvent::isDynamicTraceOpen_ = false;
377 return retCode;
378 }
379
DoCaptureTrace()380 int32_t StopTraceState::DoCaptureTrace()
381 {
382 if (!appTraceContext_->isOpenTrace_) {
383 HIVIEW_LOGI("as start trace failed, does not need stop trace for uid=%{public}d pid=%{public}d",
384 appCallerEvent_->uid_, appCallerEvent_->pid_);
385 return 0;
386 }
387
388 if (appTraceContext_->isTraceOn_) {
389 std::shared_ptr<UCollectUtil::TraceCollector> traceCollector = UCollectUtil::TraceCollector::Create();
390 CollectResult<std::vector<std::string>> result = traceCollector->TraceOff();
391 if (result.retCode != UCollect::UcError::SUCCESS) {
392 HIVIEW_LOGE("trace off for uid=%{public}d pid=%{public}d error code=%{public}d",
393 appCallerEvent_->uid_, appCallerEvent_->pid_, result.retCode);
394 }
395 }
396
397 HIVIEW_LOGI("%{public}s for uid=%{public}d pid=%{public}d",
398 (appTraceContext_->isDumpTrace_ ? "stop trace" : "no dump"), appCallerEvent_->uid_, appCallerEvent_->pid_);
399
400 TraceManager manager;
401 int32_t retCode = manager.CloseTrace();
402 if (retCode != UCollect::UcError::SUCCESS) {
403 HIVIEW_LOGE("close trace for uid=%{public}d pid=%{public}d error code=%{public}d",
404 appCallerEvent_->uid_, appCallerEvent_->pid_, retCode);
405 }
406 return 0;
407 }
408 }; // HiviewDFX
409 }; // HiviewDFX