1/* 2 * Copyright (c) Huawei Technologies Co., Ltd. 2023. 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 "ffrt_converter.h" 16 17namespace SysTuning { 18namespace TraceStreamer { 19bool FfrtConverter::RecoverTraceAndGenerateNewFile(const std::string &ffrtFileName, std::ofstream &outFile) 20{ 21 std::ifstream ffrtFile(ffrtFileName); 22 if (!ffrtFile.is_open() || !outFile.is_open()) { 23 TS_LOGE("ffrtFile or outFile is invalid."); 24 return false; 25 } 26 std::string line; 27 while (std::getline(ffrtFile, line)) 28 context_.emplace_back(line); 29 ffrtFile.close(); 30 InitTracingMarkerKey(); 31 ClassifyContextForFfrtWorker(); 32 ConvertFfrtThreadToFfrtTask(); 33 for (const std::string &oneLine : context_) { 34 outFile << oneLine << std::endl; 35 } 36 Clear(); 37 return true; 38} 39void FfrtConverter::Clear() 40{ 41 context_.clear(); 42 ffrtPidMap_.clear(); 43 taskLabels_.clear(); 44} 45void FfrtConverter::InitTracingMarkerKey() 46{ 47 for (auto line : context_) { 48 if (line.find(" tracing_mark_write: ") != std::string::npos) { 49 tracingMarkerKey_ = "tracing_mark_write: "; 50 break; 51 } 52 if (line.find(" print: ") != std::string::npos) { 53 tracingMarkerKey_ = "print: "; 54 break; 55 } 56 } 57} 58int FfrtConverter::ExtractProcessId(const size_t index) 59{ 60 std::smatch match; 61 static const std::regex pidPattern = std::regex(R"(\(\s*\d+\) \[)"); 62 if (!std::regex_search(context_[index], match, pidPattern)) { 63 return 0; 64 } 65 for (size_t i = 0; i < match.size(); i++) { 66 if (match[i] == '-') { 67 return 0; 68 } 69 } 70 auto beginPos = match.str().find('(') + 1; 71 auto endPos = match.str().find(')'); 72 return std::stoi(match.str().substr(beginPos, endPos - beginPos)); 73} 74 75std::string FfrtConverter::ExtractTimeStr(const std::string &log) 76{ 77 std::smatch match; 78 static const std::regex timePattern = std::regex(R"( (\d+)\.(\d+):)"); 79 if (std::regex_search(log, match, timePattern)) { 80 return match.str().substr(1, match.str().size() - STR_LEGH); 81 } 82 return ""; 83} 84 85std::string FfrtConverter::ExtractCpuId(const std::string &log) 86{ 87 std::smatch match; 88 static const std::regex cpuIdPattern = std::regex(R"(\) \[.*?\])"); 89 if (std::regex_search(log, match, cpuIdPattern)) { 90 auto beginPos = match.str().find('[') + 1; 91 auto endPos = match.str().find(']'); 92 return match.str().substr(beginPos, endPos - beginPos); 93 } 94 return ""; 95} 96 97std::string FfrtConverter::MakeBeginFakeLog(const std::string &mark, 98 const long long gid, 99 const int prio, 100 const ThreadInfo &threadInfo) 101{ 102 auto beginTimeStamp = ExtractTimeStr(mark); 103 auto cpuId = ExtractCpuId(mark); 104 std::unique_ptr<char[]> result = std::make_unique<char[]>(MAX_LEN); 105 auto taskId = GetTaskId(threadInfo.pid, gid); 106 (void)sprintf_s( 107 result.get(), MAX_LEN, 108 "\n %s-%d (%7d) [%s] .... %s: sched_switch: prev_comm=%s prev_pid=%d prev_prio=%d prev_state=S ==> " 109 "next_comm=%s next_pid=%s next_prio=%d\n", 110 threadInfo.name.c_str(), threadInfo.tid, threadInfo.pid, cpuId.c_str(), beginTimeStamp.c_str(), 111 threadInfo.name.c_str(), threadInfo.tid, prio, taskLabels_[threadInfo.pid][gid].c_str(), taskId.c_str(), prio); 112 return mark + result.get(); 113} 114 115std::string FfrtConverter::MakeEndFakeLog(const std::string &mark, 116 const long long gid, 117 const int prio, 118 const ThreadInfo &threadInfo) 119{ 120 auto endTimeStamp = ExtractTimeStr(mark); 121 auto cpuId = ExtractCpuId(mark); 122 std::unique_ptr<char[]> result = std::make_unique<char[]>(MAX_LEN); 123 auto taskId = GetTaskId(threadInfo.pid, gid); 124 (void)sprintf_s( 125 result.get(), MAX_LEN, 126 " %s-%s (%7d) [%s] .... %s: sched_switch: prev_comm=%s prev_pid=%s prev_prio=%d prev_state=S ==> " 127 "next_comm=%s next_pid=%d next_prio=%d\n", 128 taskLabels_[threadInfo.pid][gid].c_str(), taskId.c_str(), threadInfo.pid, cpuId.c_str(), endTimeStamp.c_str(), 129 taskLabels_[threadInfo.pid][gid].c_str(), taskId.c_str(), prio, threadInfo.name.c_str(), threadInfo.tid, prio); 130 std::string fakeLog = result.get(); 131 memset_s(result.get(), MAX_LEN, 0, MAX_LEN); 132 return fakeLog; 133} 134 135std::string FfrtConverter::ReplaceSchedSwitchLog(std::string &fakeLog, 136 const std::string &mark, 137 const int pid, 138 const long long gid, 139 const int tid) 140{ 141 std::unique_ptr<char[]> result = std::make_unique<char[]>(MAX_LEN); 142 std::smatch match; 143 auto taskId = GetTaskId(pid, gid); 144 if (mark.find("prev_pid=" + std::to_string(tid)) != std::string::npos) { 145 if (regex_search(fakeLog, match, indexPattern_) && fakeLog.find("prev_comm=") != std::string::npos && 146 fakeLog.find("prev_prio=") != std::string::npos) { 147 auto beginPos = fakeLog.find(match.str()); 148 (void)sprintf_s(result.get(), MAX_LEN, " %s-%s ", taskLabels_[pid][gid].c_str(), taskId.c_str()); 149 fakeLog = result.get() + fakeLog.substr(beginPos); 150 size_t pcommPos = fakeLog.find("prev_comm="); 151 size_t pPidPos = fakeLog.find("prev_pid="); 152 memset_s(result.get(), MAX_LEN, 0, MAX_LEN); 153 (void)sprintf_s(result.get(), MAX_LEN, "prev_comm=%s ", taskLabels_[pid][gid].c_str()); 154 fakeLog = fakeLog.substr(0, pcommPos) + result.get() + fakeLog.substr(pPidPos); 155 memset_s(result.get(), MAX_LEN, 0, MAX_LEN); 156 pPidPos = fakeLog.find("prev_pid="); 157 size_t pPrioPos = fakeLog.find("prev_prio="); 158 (void)sprintf_s(result.get(), MAX_LEN, "prev_pid=%s ", taskId.c_str()); 159 fakeLog = fakeLog.substr(0, pPidPos) + result.get() + fakeLog.substr(pPrioPos); 160 memset_s(result.get(), MAX_LEN, 0, MAX_LEN); 161 } 162 } else if (mark.find("next_pid=" + std::to_string(tid)) != std::string::npos && 163 fakeLog.find("next_comm=") != std::string::npos && fakeLog.find("next_prio=") != std::string::npos) { 164 (void)sprintf_s(result.get(), MAX_LEN, "next_comm=%s ", taskLabels_[pid][gid].c_str()); 165 size_t nCommPos = fakeLog.find("next_comm="); 166 size_t nPidPos = fakeLog.find("next_pid="); 167 fakeLog = fakeLog.substr(0, nCommPos) + result.get() + fakeLog.substr(nPidPos); 168 memset_s(result.get(), MAX_LEN, 0, MAX_LEN); 169 (void)sprintf_s(result.get(), MAX_LEN, "next_pid=%s ", taskId.c_str()); 170 nPidPos = fakeLog.find("next_pid="); 171 size_t nPrioPos = fakeLog.find("next_prio="); 172 fakeLog = fakeLog.substr(0, nPidPos) + result.get() + fakeLog.substr(nPrioPos); 173 } 174 return fakeLog; 175} 176 177std::string FfrtConverter::ReplaceSchedWakeLog(std::string &fakeLog, 178 const std::string &label, 179 const int pid, 180 const long long gid) 181{ 182 std::unique_ptr<char[]> result = std::make_unique<char[]>(MAX_LEN); 183 auto taskId = GetTaskId(pid, gid); 184 (void)sprintf_s(result.get(), MAX_LEN, "comm=%s ", label.c_str()); 185 size_t commPos = fakeLog.find("comm="); 186 size_t pidPos = fakeLog.find("pid="); 187 if (commPos != std::string::npos && pidPos != std::string::npos) { 188 fakeLog = fakeLog.substr(0, commPos) + result.get() + fakeLog.substr(pidPos); 189 memset_s(result.get(), MAX_LEN, 0, MAX_LEN); 190 (void)sprintf_s(result.get(), MAX_LEN, "pid=%s ", taskId.c_str()); 191 pidPos = fakeLog.find("pid="); 192 size_t prioPos = fakeLog.find("prio="); 193 if (prioPos != std::string::npos) { 194 fakeLog = fakeLog.substr(0, pidPos) + result.get() + fakeLog.substr(prioPos); 195 } 196 } 197 return fakeLog; 198} 199 200std::string FfrtConverter::ReplaceSchedBlockLog(std::string &fakeLog, const int pid, const long long gid) 201{ 202 std::unique_ptr<char[]> result = std::make_unique<char[]>(MAX_LEN); 203 auto taskId = GetTaskId(pid, gid); 204 (void)sprintf_s(result.get(), MAX_LEN, "pid=%s ", taskId.c_str()); 205 size_t pidPos = fakeLog.find("pid"); 206 size_t ioPos = fakeLog.find("iowait="); 207 if (pidPos != std::string::npos && ioPos != std::string::npos) { 208 fakeLog = fakeLog.substr(0, pidPos) + result.get() + fakeLog.substr(ioPos); 209 } 210 return fakeLog; 211} 212std::string FfrtConverter::ReplaceTracingMarkLog(std::string &fakeLog, 213 const std::string &label, 214 const int pid, 215 const long long gid) 216{ 217 std::unique_ptr<char[]> result = std::make_unique<char[]>(MAX_LEN); 218 std::smatch match; 219 auto taskId = GetTaskId(pid, gid); 220 if (regex_search(fakeLog, match, indexPattern_)) { 221 auto beginPos = fakeLog.find(match.str()); 222 (void)sprintf_s(result.get(), MAX_LEN, " %s-%s ", label.c_str(), taskId.c_str()); 223 fakeLog = result.get() + fakeLog.substr(beginPos); 224 } 225 return fakeLog; 226} 227std::string FfrtConverter::ConvertWorkerLogToTask(const std::string &mark, 228 const int pid, 229 const long long gid, 230 const int tid) 231{ 232 std::string fakeLog = mark; 233 if (mark.find("sched_switch: ") != std::string::npos) { 234 return ReplaceSchedSwitchLog(fakeLog, mark, pid, gid, tid); 235 } 236 if (mark.find(": sched_wak") != std::string::npos) { 237 return ReplaceSchedWakeLog(fakeLog, taskLabels_[pid][gid], pid, gid); 238 } 239 if (mark.find("sched_blocked_reason: ") != std::string::npos) { 240 return ReplaceSchedBlockLog(fakeLog, pid, gid); 241 } 242 return ReplaceTracingMarkLog(fakeLog, taskLabels_[pid][gid], pid, gid); 243} 244int FfrtConverter::FindIntNumberAfterStr(const size_t index, const string &str) 245{ 246 auto beginPos = context_[index].find(str); 247 if (beginPos != std::string::npos) { 248 beginPos = beginPos + str.length(); 249 auto endPos = context_[index].find_first_of(" ", beginPos); 250 return stoi(context_[index].substr(beginPos, endPos - beginPos)); 251 } 252 return -1; 253} 254std::string FfrtConverter::FindSubStrAfterStr(const size_t index, const string &str) 255{ 256 auto beginPos = context_[index].find(str) + str.length(); 257 auto endPos = context_[index].find_first_of(" ", beginPos); 258 return context_[index].substr(beginPos, endPos - beginPos); 259} 260void FfrtConverter::ClassifySchedSwitchData(const size_t index, std::unordered_map<int, std::vector<int>> &traceMap) 261{ 262 auto prevTid = FindIntNumberAfterStr(index, "prev_pid="); 263 auto nextTid = FindIntNumberAfterStr(index, "next_pid="); 264 // update sched_switch prev_pid and next_pid corresponding line number 265 if (prevTid != -1 && traceMap.count(prevTid) == 0) { 266 traceMap[prevTid] = std::vector<int>(); 267 } 268 if (nextTid != -1 && traceMap.count(nextTid) == 0) { 269 traceMap[nextTid] = std::vector<int>(); 270 } 271 traceMap[prevTid].push_back(index); 272 traceMap[nextTid].push_back(index); 273 274 // Get thread name as ffrtxxx or OS_FFRTxxx 275 if (context_[index].find("prev_comm=ffrt") != std::string::npos || 276 context_[index].find("prev_comm=OS_FFRT") != std::string::npos) { 277 auto pid = ExtractProcessId(index); 278 if (ffrtPidMap_.count(pid) == 0 || ffrtPidMap_[pid].count(prevTid) == 0) { 279 ffrtPidMap_[pid][prevTid].name = FindSubStrAfterStr(index, "prev_comm="); 280 } 281 } 282 return; 283} 284void FfrtConverter::FindFfrtProcessAndClassify(const size_t index, std::unordered_map<int, std::vector<int>> &traceMap) 285{ 286 if (context_[index].find("sched_switch") != std::string::npos) { 287 ClassifySchedSwitchData(index, traceMap); 288 return; 289 } 290 if (context_[index].find(": sched_wak") != std::string::npos || 291 (context_[index].find("sched_blocked_reason:") != std::string::npos)) { 292 auto tid = FindIntNumberAfterStr(index, "pid="); 293 if (traceMap.find(tid) == traceMap.end()) { 294 traceMap[tid] = std::vector<int>(); 295 } 296 traceMap[tid].push_back(index); 297 return; 298 } 299 static std::smatch match; 300 if (std::regex_search(context_[index], match, matchPattern_)) { 301 auto endPos = context_[index].find(match.str()); 302 std::string res = context_[index].substr(0, endPos); 303 std::string begin = "-"; 304 auto beginPos = res.find_last_of(begin); 305 if (beginPos != std::string::npos) { 306 beginPos = beginPos + begin.length(); 307 auto tid = stoi(context_[index].substr(beginPos, endPos - beginPos)); 308 if (traceMap.find(tid) == traceMap.end()) { 309 traceMap[tid] = std::vector<int>(); 310 } 311 traceMap[tid].push_back(index); 312 } 313 } 314 return; 315} 316 317std::string FfrtConverter::GetTaskId(int pid, long long gid) 318{ 319 stringstream ss; 320 ss << pid << "0" << gid; 321 auto str = ss.str(); 322 while (str.size() > uint32MaxLength_) { 323 str.erase(0, 1); 324 } 325 auto result = stoll(str); 326 if (result > INVALID_UINT32) { 327 str.erase(0, 1); 328 } 329 return str; 330} 331 332bool FfrtConverter::IsDigit(const std::string &str) 333{ 334 auto endPos = str.find_last_not_of(" "); 335 string newStr = str; 336 newStr.erase(endPos + 1); 337 if (newStr.back() == '\r') { 338 newStr.pop_back(); 339 } 340 for (int i = 0; i < newStr.length(); i++) { 341 if (!std::isdigit(newStr[i])) { 342 return false; 343 } 344 } 345 return true; 346} 347 348void FfrtConverter::ClassifyContextForFfrtWorker() 349{ 350 std::unordered_map<int, std::vector<int>> traceMap; 351 for (auto index = 0; index < context_.size(); index++) { 352 FindFfrtProcessAndClassify(index, traceMap); 353 } 354 for (auto &[pid, threads] : ffrtPidMap_) { 355 for (const auto &thread : threads) { 356 auto tid = thread.first; 357 ffrtPidMap_[pid][tid].indices = traceMap[tid]; 358 } 359 } 360} 361void FfrtConverter::ConvertFfrtThreadToFfrtTask() 362{ 363 int prio; 364 for (auto &[pid, threads] : ffrtPidMap_) { 365 taskLabels_[pid] = {}; 366 for (auto &[tid, ffrtContent] : ffrtPidMap_[pid]) { 367 ThreadInfo threadInfo; 368 threadInfo.pid = pid; 369 threadInfo.tid = tid; 370 threadInfo.name = ffrtContent.name; 371 auto switchInFakeLog = false; 372 auto switchOutFakeLog = false; 373 auto ffbkMarkRemove = false; 374 auto gid = WAKE_EVENT_DEFAULT_VALUE; 375 for (auto index : ffrtContent.indices) { 376 ProcessMarkWithSchedSwitch(tid, prio, index); 377 if (context_[index].find("|FFRT") != std::string::npos || 378 context_[index].find("|H:FFRT") != std::string::npos) { 379 if (!ProcessMarkWithFFRT(index, prio, gid, threadInfo)) { 380 continue; 381 } 382 switchInFakeLog = true; 383 continue; 384 } 385 if (gid != WAKE_EVENT_DEFAULT_VALUE) { 386 if (!DeleteRedundance(switchInFakeLog, switchOutFakeLog, index)) { 387 continue; 388 } 389 static const std::regex EndPattern = std::regex(R"( F\|(\d+)\|[BF]\|(\d+))"); 390 static const std::regex HEndPattern = std::regex(R"( F\|(\d+)\|H:[BF]\s(\d+))"); 391 if (std::regex_search(context_[index], EndPattern) || 392 std::regex_search(context_[index], HEndPattern)) { 393 context_[index] = MakeEndFakeLog(context_[index], gid, prio, threadInfo); 394 gid = WAKE_EVENT_DEFAULT_VALUE; 395 switchOutFakeLog = false; 396 continue; 397 } 398 context_[index] = ConvertWorkerLogToTask(context_[index], pid, gid, tid); 399 continue; 400 } 401 } 402 } 403 } 404} 405void FfrtConverter::ProcessMarkWithSchedSwitch(const int tid, int &prio, const size_t index) 406{ 407 if (context_[index].find("sched_switch:") != std::string::npos) { 408 if (context_[index].find("prev_pid=" + std::to_string(tid) + " ") != std::string::npos) { 409 static std::string beginPprio = "prev_prio="; 410 auto beginPos = context_[index].find(beginPprio); 411 if (beginPos != std::string::npos) { 412 beginPos = beginPos + beginPprio.length(); 413 auto endPos = context_[index].find_first_of(" ", beginPos); 414 prio = stoi(context_[index].substr(beginPos, endPos - beginPos)); 415 } 416 } else if (context_[index].find("next_pid=" + std::to_string(tid)) != std::string::npos) { 417 static std::string beginNprio = "next_prio="; 418 auto beginPos = context_[index].find(beginNprio); 419 if (beginPos != std::string::npos) { 420 beginPos = beginPos + beginNprio.length(); 421 prio = stoi(context_[index].substr(beginPos)); 422 } 423 } 424 } 425} 426std::string FfrtConverter::GetLabel(const string &line) 427{ 428 std::string label; 429 if (line.find("|H:FFRT") != std::string::npos) { 430 if (line.find("H:FFRT::") != std::string::npos) { 431 auto beginPos = line.rfind("["); 432 auto endPos = line.rfind("]"); 433 if (beginPos != std::string::npos && endPos != std::string::npos) { 434 label = line.substr(beginPos + 1, endPos - beginPos - 1); 435 } 436 } else { 437 static std::string indexHFfrt = "|H:FFRT"; 438 auto beginPos = line.find(indexHFfrt); 439 beginPos = beginPos + indexHFfrt.length(); 440 auto endPos = line.find_first_of("|", beginPos); 441 if (endPos != std::string::npos) { 442 label = line.substr(beginPos, endPos - beginPos); 443 } 444 } 445 } else { 446 if (line.find("|FFRT::") != std::string::npos) { 447 auto beginPos = line.rfind("["); 448 auto endPos = line.rfind("]"); 449 if (beginPos != std::string::npos && endPos != std::string::npos) { 450 label = line.substr(beginPos + 1, endPos - beginPos - 1); 451 } 452 } else { 453 static std::string indexFfrt = "|FFRT"; 454 auto beginPos = line.find(indexFfrt); 455 beginPos = beginPos + indexFfrt.length(); 456 auto endPos = line.find_first_of("|", beginPos); 457 if (endPos != std::string::npos) { 458 label = line.substr(beginPos, endPos - beginPos); 459 } 460 } 461 } 462 return label; 463} 464bool FfrtConverter::ProcessMarkWithFFRT(const int index, int &prio, int32_t &gid, const ThreadInfo &threadInfo) 465{ 466 auto line = context_[index]; 467 auto label = GetLabel(line); 468 if (label.find("executor_task") != std::string::npos || label.find("ex_task") != std::string::npos) { 469 return false; 470 } 471 std::string missLog; 472 if (gid != WAKE_EVENT_DEFAULT_VALUE) { 473 missLog = MakeEndFakeLog(line, gid, prio, threadInfo); 474 auto timestamp = ExtractTimeStr(line); 475 auto cpuId = ExtractCpuId(line); 476 std::unique_ptr<char[]> result = std::make_unique<char[]>(MAX_LEN); 477 (void)sprintf_s(result.get(), MAX_LEN, " %s-%d (%7d) [%s] .... %s: %sE|%d\n", threadInfo.name.c_str(), 478 threadInfo.tid, threadInfo.pid, cpuId.c_str(), timestamp.c_str(), tracingMarkerKey_.c_str(), 479 threadInfo.pid); 480 missLog = missLog + result.get(); 481 memset_s(result.get(), MAX_LEN, 0, MAX_LEN); 482 } 483 auto beginPos = line.rfind("|"); 484 if (beginPos == std::string::npos || !IsDigit(line.substr(beginPos + 1))) { 485 return false; 486 } 487 gid = stoll(line.substr(beginPos + 1)); 488 if (taskLabels_[threadInfo.pid].count(gid) == 0) { 489 taskLabels_[threadInfo.pid][gid] = label; 490 } 491 context_[index] = MakeBeginFakeLog(line, gid, prio, threadInfo); 492 if (!missLog.empty()) { 493 context_[index] = missLog + context_[index]; 494 } 495 return true; 496} 497bool FfrtConverter::DeleteRedundance(bool &switchInFakeLog, bool &switchOutFakeLog, const int index) 498{ 499 static const std::regex CoPattern = std::regex(R"( F\|(\d+)\|Co\|(\d+))"); 500 static const std::regex HCoPattern = std::regex(R"( F\|(\d+)\|H:Co\s(\d+))"); 501 if (std::regex_search(context_[index], CoPattern) || std::regex_search(context_[index], HCoPattern)) { 502 context_[index].clear(); 503 if (switchInFakeLog) { 504 switchInFakeLog = false; 505 return false; 506 } else { 507 switchOutFakeLog = true; 508 return false; 509 } 510 } 511 if (switchInFakeLog && (context_[index].find(tracingMarkerKey_ + "B") != std::string::npos)) { 512 context_[index].clear(); 513 return false; 514 } 515 if (switchOutFakeLog && (context_[index].find(tracingMarkerKey_ + "E") != std::string::npos)) { 516 context_[index].clear(); 517 return false; 518 } 519 return true; 520} 521} // namespace TraceStreamer 522} // namespace SysTuning 523