已合并
feat: add binary dump of args as a debugging measure on AICPU exception #3815
feat: add binary dump of args as a debugging measure on AICPU exception #3815
已合并
rui创建于 7月24日
共 2 个文件变更+225-3
@@ -30,6 +30,8 @@
30#include "task_execute_time.h"30#include "task_execute_time.h"
31#include "ffts_task.h"31#include "ffts_task.h"
32#include "printf.hpp"32#include "printf.hpp"
33+#include <sstream>
王
王王璐瑶7月28日

这个头文件还需要吗?

likedislike
rui
7月28日 评论:
34+#include <vector>
33 35 
34namespace cce {36namespace cce {
35namespace runtime {37namespace runtime {
@@ -612,6 +614,57 @@ void GetSoNameForAiCpu(TaskInfo* taskInfo, std::string& nameInfo)
612 devArgLdr->GetKernelInfoFromAddr(nameInfo, KernelInfoType::SO_NAME, taskInfo->u.aicpuTaskInfo.soName);614 devArgLdr->GetKernelInfoFromAddr(nameInfo, KernelInfoType::SO_NAME, taskInfo->u.aicpuTaskInfo.soName);
613}615}
614 616 
617+static void DumpAicpuArgsForDfx(TaskInfo* taskInfo, const uint32_t devId)
618+{
619+ AicpuTaskInfo* aicpuTaskInfo = &(taskInfo->u.aicpuTaskInfo);
620+ const uint16_t taskId = taskInfo->id;
621+ const int32_t streamId = taskInfo->stream->Id_();
622+ if ((aicpuTaskInfo->comm.args == nullptr) || (aicpuTaskInfo->comm.argsSize == 0U)) {
623+ return;
624+ }
625+ const uint32_t argsSize = aicpuTaskInfo->comm.argsSize;
626+ const uint64_t argsDevAddr = RtPtrToValue(aicpuTaskInfo->comm.args);
627+ const uint64_t soNameDevAddr = RtPtrToValue(aicpuTaskInfo->soName);
628+ const uint64_t kernelNameDevAddr = RtPtrToValue(aicpuTaskInfo->funcName);
629+ 
630+ std::vector<uint8_t> hostBuf(argsSize + 1U);
631+ const rtError_t error = taskInfo->stream->Device_()->Driver_()->MemCopySync(
632+ hostBuf.data(), static_cast<uint64_t>(argsSize), aicpuTaskInfo->comm.args, static_cast<uint64_t>(argsSize),
633+ RT_MEMCPY_DEVICE_TO_HOST);
634+ if (error != RT_ERROR_NONE) {
635+ RT_LOG(
636+ RT_LOG_ERROR, "MemCopySync failed, device_id=%u, stream_id=%d, task_id=%u, retCode=%#x, argsSize=%u.",
637+ devId, streamId, static_cast<uint32_t>(taskId), static_cast<uint32_t>(error), argsSize);
638+ return;
639+ }
640+ hostBuf[argsSize] = 0U;
641+ 
642+ if ((aicpuTaskInfo->soName != nullptr) && (soNameDevAddr >= argsDevAddr) &&
643+ ((soNameDevAddr - argsDevAddr) < static_cast<uint64_t>(argsSize))) {
644+ const uint64_t soNameOffset = soNameDevAddr - argsDevAddr;
645+ const auto soNamePtr = RtPtrToPtr<const char*>(hostBuf.data() + soNameOffset);
646+ const size_t soNameLen = strnlen(soNamePtr, static_cast<size_t>(argsSize - soNameOffset));
647+ RT_LOG(
648+ RT_LOG_ERROR,
649+ "[AICPU_INFO] soName=%s, strLen=%lu, remainingLen=%lu, device_id=%u, stream_id=%d, "
650+ "task_id=%u.",
651+ soNamePtr, soNameLen, static_cast<uint64_t>(argsSize) - soNameOffset, devId, streamId,
652+ static_cast<uint32_t>(taskId));
653+ }
654+ if ((aicpuTaskInfo->funcName != nullptr) && (kernelNameDevAddr >= argsDevAddr) &&
655+ ((kernelNameDevAddr - argsDevAddr) < static_cast<uint64_t>(argsSize))) {
656+ const uint64_t kernelNameOffset = kernelNameDevAddr - argsDevAddr;
657+ const auto kernelNamePtr = RtPtrToPtr<const char*>(hostBuf.data() + kernelNameOffset);
658+ const size_t kernelNameLen = strnlen(kernelNamePtr, static_cast<size_t>(argsSize - kernelNameOffset));
659+ RT_LOG(
660+ RT_LOG_ERROR,
661+ "[AICPU_INFO] kernelName=%s, strLen=%lu, remainingLen=%lu, device_id=%u, stream_id=%d, "
662+ "task_id=%u.",
663+ kernelNamePtr, kernelNameLen, static_cast<uint64_t>(argsSize) - kernelNameOffset, devId, streamId,
664+ static_cast<uint32_t>(taskId));
665+ }
666+}
667+ 
615static void PrintAicpuErrorInfo(TaskInfo* taskInfo, const uint32_t devId)668static void PrintAicpuErrorInfo(TaskInfo* taskInfo, const uint32_t devId)
616{669{
617 AicpuTaskInfo* aicpuTaskInfo = &(taskInfo->u.aicpuTaskInfo);670 AicpuTaskInfo* aicpuTaskInfo = &(taskInfo->u.aicpuTaskInfo);
@@ -658,6 +711,9 @@ static void PrintAicpuErrorInfo(TaskInfo* taskInfo, const uint32_t devId)
658 711 
659 Stream* const reportStream = GetReportStream(taskInfo->stream);712 Stream* const reportStream = GetReportStream(taskInfo->stream);
660 std::string extendInfo;713 std::string extendInfo;
714+ if (soName.empty() && kernelName.empty()) {
715+ DumpAicpuArgsForDfx(taskInfo, devId);
716+ }
661 if ((aicpuKernelType == TS_AICPU_KERNEL_AICPU) || (aicpuKernelType == TS_AICPU_KERNEL_CUSTOM_AICPU)) {717 if ((aicpuKernelType == TS_AICPU_KERNEL_AICPU) || (aicpuKernelType == TS_AICPU_KERNEL_CUSTOM_AICPU)) {
662 STREAM_REPORT_ERR_MSG(718 STREAM_REPORT_ERR_MSG(
663 reportStream, ERR_MODULE_AICPU,719 reportStream, ERR_MODULE_AICPU,
@@ -17,6 +17,8 @@
17#include "stars.hpp"17#include "stars.hpp"
18#include "hwts.hpp"18#include "hwts.hpp"
19#include "rt_unwrap.h"19#include "rt_unwrap.h"
20+#include "runtime.hpp"
21+#include "raw_device.hpp"
20#include "notify.hpp"22#include "notify.hpp"
21#undef protected23#undef protected
22#undef private24#undef private
@@ -26,9 +28,8 @@
26#include "model_execute_task.h"28#include "model_execute_task.h"
27#include "task_info_v100.h"29#include "task_info_v100.h"
28#include "task_info.hpp"30#include "task_info.hpp"
29-#include "runtime.hpp"31+#include "npu_driver.hpp"
30#include "model.hpp"32#include "model.hpp"
31-#include "raw_device.hpp"
32#include "thread_local_container.hpp"33#include "thread_local_container.hpp"
33#include "log_types.h"34#include "log_types.h"
34#include "task_execute_time.h"35#include "task_execute_time.h"
@@ -39,10 +40,47 @@
39#include "cond_op_stream_task.h"40#include "cond_op_stream_task.h"
40#include "stream_task.h"41#include "stream_task.h"
41#include "task_res.hpp"42#include "task_res.hpp"
43+#include "davinci_kernel_task.h"
42#include "event.hpp"44#include "event.hpp"
43 45 
44using namespace cce::runtime;46using namespace cce::runtime;
45 47 
48+namespace {
49+constexpr uint32_t DUMP_ARGS_SIZE = 256U;
50+constexpr uint64_t DUMP_ARGS_BASE = 0x1000ULL;
51+uint8_t g_dumpArgsBuf[DUMP_ARGS_SIZE] = {};
52+bool g_memCopySyncFail = false;
53+ 
54+rtError_t DumpAicpuArgsMemCopyStub(
55+ Driver* drv, void* dst, uint64_t destMax, const void* src, uint64_t size, rtMemcpyKind_t kind)
56+{
57+ if (g_memCopySyncFail) {
58+ return RT_ERROR_INVALID_VALUE;
59+ }
60+ (void)memcpy_s(dst, static_cast<size_t>(destMax), g_dumpArgsBuf, static_cast<size_t>(size));
61+ return RT_ERROR_NONE;
62+}
63+ 
64+void InitAicpuTaskInfoForDump(
65+ TaskInfo& taskInfo, Stream* stream, uint32_t argsSize, void* args, void* soName, void* funcName)
66+{
67+ taskInfo.stream = stream;
68+ taskInfo.type = TS_TASK_TYPE_KERNEL_AICPU;
69+ taskInfo.errorCode = 0x2A;
70+ taskInfo.id = 42;
71+ taskInfo.u.aicpuTaskInfo.kernel = nullptr;
72+ taskInfo.u.aicpuTaskInfo.aicpuKernelType = TS_AICPU_KERNEL_AICPU;
73+ taskInfo.u.aicpuTaskInfo.kernelInnerHandle = nullptr;
74+ taskInfo.u.aicpuTaskInfo.comm.argsSize = argsSize;
75+ taskInfo.u.aicpuTaskInfo.comm.args = args;
76+ taskInfo.u.aicpuTaskInfo.soName = soName;
77+ taskInfo.u.aicpuTaskInfo.funcName = funcName;
78+ taskInfo.u.aicpuTaskInfo.headParamOffset = 0;
79+ taskInfo.u.aicpuTaskInfo.aicpuFlags = 0;
80+ taskInfo.u.aicpuTaskInfo.timeout = 0;
81+}
82+} // namespace
83+ 
46class Arch5162TaskTest : public testing::Test {84class Arch5162TaskTest : public testing::Test {
47protected:85protected:
48 static void SetUpTestCase() { std::cout << "Arch5162TaskTest test start" << std::endl; }86 static void SetUpTestCase() { std::cout << "Arch5162TaskTest test start" << std::endl; }
@@ -793,6 +831,34 @@ TEST_F(Arch5162TaskTest, ConstructSqeForProfilingDisableTask)
793 delete device;831 delete device;
794}832}
795 833 
834+TEST_F(Arch5162TaskTest, DumpAicpuArgsForDfx_ArgsNull)
835+{
836+ RawDevice* device = new RawDevice(0);
837+ Stream* stream = new Stream(device, 0);
838+ ASSERT_NE(stream, nullptr);
839+ 
840+ TaskInfo taskInfo = {};
841+ taskInfo.stream = stream;
842+ taskInfo.type = TS_TASK_TYPE_KERNEL_AICPU;
843+ taskInfo.errorCode = 0x2A;
844+ taskInfo.id = 42;
845+ taskInfo.u.aicpuTaskInfo.kernel = nullptr;
846+ taskInfo.u.aicpuTaskInfo.aicpuKernelType = TS_AICPU_KERNEL_AICPU;
847+ taskInfo.u.aicpuTaskInfo.kernelInnerHandle = nullptr;
848+ taskInfo.u.aicpuTaskInfo.comm.argsSize = 0;
849+ taskInfo.u.aicpuTaskInfo.comm.args = nullptr;
850+ taskInfo.u.aicpuTaskInfo.soName = nullptr;
851+ taskInfo.u.aicpuTaskInfo.funcName = nullptr;
852+ taskInfo.u.aicpuTaskInfo.headParamOffset = 0;
853+ taskInfo.u.aicpuTaskInfo.aicpuFlags = 0;
854+ taskInfo.u.aicpuTaskInfo.timeout = 0;
855+ 
856+ PrintErrorInfoForDavinciTask(&taskInfo, 0);
857+ 
858+ delete stream;
859+ delete device;
860+}
861+ 
796TEST_F(Arch5162TaskTest, ModelExecuteTaskInit_nullptr)862TEST_F(Arch5162TaskTest, ModelExecuteTaskInit_nullptr)
797{863{
798 rtError_t ret = ModelExecuteTaskInit(nullptr, nullptr, 0U, 0U);864 rtError_t ret = ModelExecuteTaskInit(nullptr, nullptr, 0U, 0U);
@@ -812,6 +878,36 @@ TEST_F(Arch5162TaskTest, ModelExecuteTaskInit_normal)
812 delete device;878 delete device;
813}879}
814 880 
881+TEST_F(Arch5162TaskTest, DumpAicpuArgsForDfx_ArgsSizeZero)
882+{
883+ RawDevice* device = new RawDevice(0);
884+ Stream* stream = new Stream(device, 0);
885+ ASSERT_NE(stream, nullptr);
886+ 
887+ char dummyBuf[8] = {};
888+ TaskInfo taskInfo = {};
889+ taskInfo.stream = stream;
890+ taskInfo.type = TS_TASK_TYPE_KERNEL_AICPU;
891+ taskInfo.errorCode = 0x2A;
892+ taskInfo.id = 42;
893+ taskInfo.u.aicpuTaskInfo.kernel = nullptr;
894+ taskInfo.u.aicpuTaskInfo.aicpuKernelType = TS_AICPU_KERNEL_AICPU;
895+ taskInfo.u.aicpuTaskInfo.kernelInnerHandle = nullptr;
896+ taskInfo.u.aicpuTaskInfo.comm.argsSize = 0;
897+ taskInfo.u.aicpuTaskInfo.comm.args = static_cast<void*>(dummyBuf);
898+ taskInfo.u.aicpuTaskInfo.soName = nullptr;
899+ taskInfo.u.aicpuTaskInfo.funcName = nullptr;
900+ taskInfo.u.aicpuTaskInfo.headParamOffset = 0;
901+ taskInfo.u.aicpuTaskInfo.aicpuFlags = 0;
902+ taskInfo.u.aicpuTaskInfo.timeout = 0;
903+ 
904+ // argsSize==0 triggers early return in DumpAicpuArgsForDfx before MemCopySync
905+ PrintErrorInfoForDavinciTask(&taskInfo, 0);
906+ 
907+ delete stream;
908+ delete device;
909+}
910+ 
815TEST_F(Arch5162TaskTest, ModelExecuteTaskUnInit)911TEST_F(Arch5162TaskTest, ModelExecuteTaskUnInit)
816{912{
817 TaskInfo taskInfo = {};913 TaskInfo taskInfo = {};
@@ -838,6 +934,26 @@ TEST_F(Arch5162TaskTest, ConstructSqeForModelExecuteTask)
838 delete device;934 delete device;
839}935}
840 936 
937+TEST_F(Arch5162TaskTest, DumpAicpuArgsForDfx_MemCopyFail)
938+{
939+ NpuDriver drv;
940+ RawDevice* device = new RawDevice(0);
941+ device->driver_ = &drv;
942+ Stream* stream = new Stream(device, 0);
943+ ASSERT_NE(stream, nullptr);
944+ 
945+ g_memCopySyncFail = true;
946+ TaskInfo taskInfo = {};
947+ InitAicpuTaskInfoForDump(taskInfo, stream, 64U, reinterpret_cast<void*>(DUMP_ARGS_BASE), nullptr, nullptr);
948+ 
949+ MOCKER_CPP_VIRTUAL(device->driver_, &Driver::MemCopySync).stubs().will(invoke(DumpAicpuArgsMemCopyStub));
950+ PrintErrorInfoForDavinciTask(&taskInfo, 0);
951+ 
952+ g_memCopySyncFail = false;
953+ delete stream;
954+ delete device;
955+}
956+ 
841TEST_F(Arch5162TaskTest, SetResultForModelExecuteTask)957TEST_F(Arch5162TaskTest, SetResultForModelExecuteTask)
842{958{
843 RawDevice* device = new RawDevice(0);959 RawDevice* device = new RawDevice(0);
@@ -852,6 +968,56 @@ TEST_F(Arch5162TaskTest, SetResultForModelExecuteTask)
852 delete device;968 delete device;
853}969}
854 970 
971+TEST_F(Arch5162TaskTest, DumpAicpuArgsForDfx_SoNameInRange)
972+{
973+ NpuDriver drv;
974+ RawDevice* device = new RawDevice(0);
975+ device->driver_ = &drv;
976+ Stream* stream = new Stream(device, 0);
977+ ASSERT_NE(stream, nullptr);
978+ 
979+ const char* soNameStr = "test_so.so";
980+ memset(g_dumpArgsBuf, 0, sizeof(g_dumpArgsBuf));
981+ memcpy_s(g_dumpArgsBuf + 64U, sizeof(g_dumpArgsBuf) - 64U, soNameStr, strlen(soNameStr) + 1U);
982+ g_memCopySyncFail = false;
983+ 
984+ TaskInfo taskInfo = {};
985+ InitAicpuTaskInfoForDump(
986+ taskInfo, stream, DUMP_ARGS_SIZE, reinterpret_cast<void*>(DUMP_ARGS_BASE),
987+ reinterpret_cast<void*>(DUMP_ARGS_BASE + 64U), nullptr);
988+ 
989+ MOCKER_CPP_VIRTUAL(device->driver_, &Driver::MemCopySync).stubs().will(invoke(DumpAicpuArgsMemCopyStub));
990+ PrintErrorInfoForDavinciTask(&taskInfo, 0);
991+ 
992+ delete stream;
993+ delete device;
994+}
995+ 
996+TEST_F(Arch5162TaskTest, DumpAicpuArgsForDfx_KernelNameInRange)
997+{
998+ NpuDriver drv;
999+ RawDevice* device = new RawDevice(0);
1000+ device->driver_ = &drv;
1001+ Stream* stream = new Stream(device, 0);
1002+ ASSERT_NE(stream, nullptr);
1003+ 
1004+ const char* kernelNameStr = "TestKernel";
1005+ memset(g_dumpArgsBuf, 0, sizeof(g_dumpArgsBuf));
1006+ memcpy_s(g_dumpArgsBuf + 128U, sizeof(g_dumpArgsBuf) - 128U, kernelNameStr, strlen(kernelNameStr) + 1U);
1007+ g_memCopySyncFail = false;
1008+ 
1009+ TaskInfo taskInfo = {};
1010+ InitAicpuTaskInfoForDump(
1011+ taskInfo, stream, DUMP_ARGS_SIZE, reinterpret_cast<void*>(DUMP_ARGS_BASE), nullptr,
1012+ reinterpret_cast<void*>(DUMP_ARGS_BASE + 128U));
1013+ 
1014+ MOCKER_CPP_VIRTUAL(device->driver_, &Driver::MemCopySync).stubs().will(invoke(DumpAicpuArgsMemCopyStub));
1015+ PrintErrorInfoForDavinciTask(&taskInfo, 0);
1016+ 
1017+ delete stream;
1018+ delete device;
1019+}
1020+ 
855TEST_F(Arch5162TaskTest, ModelExecuteTaskRegister)1021TEST_F(Arch5162TaskTest, ModelExecuteTaskRegister)
856{1022{
857 EXPECT_NE(g_taskFuncArrays[CHIP_5162A].toSqeFunc[TS_TASK_TYPE_MODEL_EXECUTE], nullptr);1023 EXPECT_NE(g_taskFuncArrays[CHIP_5162A].toSqeFunc[TS_TASK_TYPE_MODEL_EXECUTE], nullptr);
@@ -1173,4 +1339,4 @@ TEST_F(Arch5162TaskTest, ModelMaintainceTaskRegister_AllFields)
1173 EXPECT_NE(g_taskFuncArrays[CHIP_5162A].printErrorInfoFunc[TS_TASK_TYPE_MODEL_MAINTAINCE], nullptr);1339 EXPECT_NE(g_taskFuncArrays[CHIP_5162A].printErrorInfoFunc[TS_TASK_TYPE_MODEL_MAINTAINCE], nullptr);
1174 EXPECT_NE(g_taskFuncArrays[CHIP_5162A].setResultFunc[TS_TASK_TYPE_MODEL_MAINTAINCE], nullptr);1340 EXPECT_NE(g_taskFuncArrays[CHIP_5162A].setResultFunc[TS_TASK_TYPE_MODEL_MAINTAINCE], nullptr);
1175 EXPECT_NE(g_taskFuncArrays[CHIP_5162A].setStarsResultFunc[TS_TASK_TYPE_MODEL_MAINTAINCE], nullptr);1341 EXPECT_NE(g_taskFuncArrays[CHIP_5162A].setStarsResultFunc[TS_TASK_TYPE_MODEL_MAINTAINCE], nullptr);
1176-}1342+}