算子的功能是做矩阵乘法的，在开发板上运行，使用aclnn单算子调用时报错：
INFO: generate input data success!
-- The C compiler identification is GNU 10.3.1
-- The CXX compiler identification is GNU 10.3.1
-- Detecting C compiler ABI info
-- Detecting C compiler ABI info - done
-- Check for working C compiler: /usr/bin/cc - skipped
-- Detecting C compile features
-- Detecting C compile features - done
-- Detecting CXX compiler ABI info
-- Detecting CXX compiler ABI info - done
-- Check for working CXX compiler: /usr/bin/c++ - skipped
-- Detecting CXX compile features
-- Detecting CXX compile features - done
-- env INC_PATH: /usr/local/Ascend/ascend-toolkit/latest
-- env LIB_PATH: /usr/local/Ascend/ascend-toolkit/latest/aarch64-linux/devlib
-- Configuring done
-- Generating done
-- Build files have been written to: /home/HwHiAiUser/workspace/CustomOperators/DeltaHiddenCustom/MatmulTest/MatrixMultiplyInvocation/build
INFO: cmake success!
[ 20%] Building CXX object CMakeFiles/execute_matmul_op.dir/operator_desc.cpp.o
[ 40%] Building CXX object CMakeFiles/execute_matmul_op.dir/op_runner.cpp.o
[ 60%] Building CXX object CMakeFiles/execute_matmul_op.dir/main.cpp.o
[ 80%] Building CXX object CMakeFiles/execute_matmul_op.dir/common.cpp.o
[100%] Linking CXX executable /home/HwHiAiUser/workspace/CustomOperators/DeltaHiddenCustom/MatmulTest/MatrixMultiplyInvocation/output/execute_matmul_op
[100%] Built target execute_matmul_op
INFO: make success!
INFO: execute op!
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:12.514.803 [task_fail_callback_data_manager.cc:58] 2605 TaskFailCallBackManager: Constructor.
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.363.276 [msprof_callback_impl.cpp:358] >>> (tid:2605) Started to register profiling ctrl callback.
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.365.355 [msprof_callback_impl.cpp:365] >>> (tid:2605) Started to register profiling hash id callback.
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.365.374 [prof_atls_plugin.cpp:117] (tid:2605) RegisterProfileCallback, callback type is 7
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.365.467 [msprof_callback_impl.cpp:372] >>> (tid:2605) Started to register profiling enable host freq callback.
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.365.541 [prof_atls_plugin.cpp:117] (tid:2605) RegisterProfileCallback, callback type is 8
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.453.324 [prof_atls_plugin.cpp:210] (tid:2605) Module[61] register callback of ctrl handle.
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.497.235 [prof_atls_plugin.cpp:210] (tid:2605) Module[45] register callback of ctrl handle.
[INFO] GE(2605,execute_matmul_op):2025-08-04-02:30:14.297.339 [op_tiling_manager.cc:109]2605 ~FuncPerfScope:[GEPERFTRACE] The time cost of OpTilingManager::LoadSo is [799877] micro seconds.
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:14.980.569 [prof_atls_plugin.cpp:210] (tid:2605) Module[6] register callback of ctrl handle.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:18.321.023 [runtime_keeper.cc:149] 2605 CreateRuntimeImpl: Open libruntime_v100.so success
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:18.322.717 [runtime.cc:5060] 2605 GetVisibleDevices: ASCEND_RT_VISIBLE_DEVICES param was not set
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:18.378.120 [prof_atls_plugin.cpp:210] (tid:2605) Module[7] register callback of ctrl handle.
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:18.380.388 [prof_atls_plugin.cpp:210] (tid:2605) Module[48] register callback of ctrl handle.
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:18.380.528 [msprof_callback_impl.cpp:110] >>> (tid:2605) MsprofCtrlCallback called, type: 255
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:18.383.541 [ai_drv_dev_api.cpp:333] >>> (tid:2605) Succeeded to DrvGetApiVersion version: 0x71f0d
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.386.674 [client_manager.cpp:464][GetClientRunMode][tid:2605] runningMode:0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.386.716 [client_manager.cpp:127][GetInstance][tid:2605] [ClientManager] Current mode:2
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.386.883 [thread_mode_manager.cpp:70][Open][tid:2605] [ThreadModeManager] enter into open process deviceId[0] rankSize[0]
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.182 [package_worker.cpp:23][RuntimePackageWorker][tid:2605] Start init RuntimePackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.298 [package_worker.cpp:23][DshapePackageWorker][tid:2605] Start init DshapePackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.367 [package_worker.cpp:23][OmPackageWorker][tid:2605] Start init OmPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.426 [package_worker.cpp:30][AicpuProcessPackageWorker][tid:2605] Start init AicpuProcessPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.486 [package_worker.cpp:30][AicpuProcessPackageWorker][tid:2605] Start init AicpuProcessPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.536 [package_worker.cpp:76][ExtendProcessPackageWorker][tid:2605] Start init ExtendProcessPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.593 [package_worker.cpp:28][AicpuThreadPackageWorker][tid:2605] Start init AicpuThreadPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.655 [package_worker.cpp:28][AicpuThreadPackageWorker][tid:2605] Start init AicpuThreadPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.706 [package_worker.cpp:62][ExtendThreadPackageWorker][tid:2605] Start init ExtendThreadPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.843 [aicpu_thread_package_worker.cpp:132][OpenVerifyFile][tid:2605] Create verify file end, path=/root/aicpu_package_install.info, reason=File exists
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.946 [aicpu_thread_package_worker.cpp:141][OpenVerifyFile][tid:2605] Create or open verify file success, path=/root/aicpu_package_install.info
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.389.586 [aicpu_thread_package_worker.cpp:132][OpenVerifyFile][tid:2605] Create verify file end, path=/root/extend_aicpu_package_install.info, reason=File exists
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.389.676 [aicpu_thread_package_worker.cpp:141][OpenVerifyFile][tid:2605] Create or open verify file success, path=/root/extend_aicpu_package_install.info
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.983.354 [thread_mode_manager.cpp:158][SetAICPUProfilingCallback][tid:2605] [ThreadModeManager] profiling callback is nullptr, skip set aicpu profiling callback
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.983.392 [aicpusd_interface_process.cpp:524][TryGetLogLevelFromParentProcess][tid:2605] get ASCEND_GLOBAL_LOG_LEVEL [3] and ASCEND_GLOBAL_EVENT_ENABLE []
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.220 [aicpusd_interface_process.cpp:466][GetCurrentRunMode][tid:2605] Current aicpu mode is offline (call by api).
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.359 [aicpusd_drv_manager.cpp:327][MarkMdc][tid:2605] Get hardware version[7] success.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.445 [aicpusd_drv_manager.cpp:190][GetNormalAicpuInfo][tid:2605] aicpuBitMap[6], aicpuNum[2].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.519 [aicpusd_drv_manager.cpp:224][GetCcpuInfo][tid:2605] ccpuBitMap[3].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.622 [aicpusd_drv_manager.cpp:110][GetNormalAicpuDCpuInfo][tid:2605] GetNormalAicpuDCpuInfo, deviceId[0], aicpu_num[2], aicpu_os_sched[281470681743361], ccpu_num[255082402676737], ccpu_os_sched[255082402676737], dcpu_num[255082402676736], dcpu_os_sched[281470681743361], tscpu_num[0], tscpu_os_sched[0].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.638 [aicpusd_drv_manager.cpp:306][InitDrvMgrCaluniqueVfId][tid:2605] InitDrvMgr uniqueVfId=0, deviceId=0
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.716 [aicpusd_drv_manager.cpp:377][InitDrvMgr][tid:2605] host pid[2605], host proc name[], vf id[0], first aicpu index[0], aicpu num[2], dcpu base index[1], dcpu num[0].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.958 [aicpusd_resource_manager.cpp:247][InitBufManager][tid:2605] Aicpu schedule SetBuffCfg successed!
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.985.517 [aicpusd_worker.cpp:74][ThreadPool][tid:2605] ThreadPool
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.985.951 [aicpusd_worker.cpp:274][AddPidToTask][tid:2610] Bind pid by hal.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.985.966 [aicpusd_worker.cpp:276][AddPidToTask][tid:2610] AddPidToTask by halBindCgroup
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.986.178 [aicpusd_worker.cpp:274][AddPidToTask][tid:2609] Bind pid by hal.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.986.191 [aicpusd_worker.cpp:276][AddPidToTask][tid:2609] AddPidToTask by halBindCgroup
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.023.577 [aicpusd_worker.cpp:323][SetAffinityBySelf][tid:2610] [hw]SetAffinityBySelf, physIndex[2], devNum[0]
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.023.624 [aicpusd_worker.cpp:323][SetAffinityBySelf][tid:2609] [hw]SetAffinityBySelf, physIndex[1], devNum[0]
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.023.626 [aicpusd_worker.cpp:389][SetAffinity][tid:2610] aicpu bind tid by self, index[1], deviceId[0], res[0].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.023.639 [aicpusd_worker.cpp:389][SetAffinity][tid:2609] aicpu bind tid by self, index[0], deviceId[0], res[0].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.023.958 [aicpusd_cust_so_manager.cpp:77][InitAicpuCustSoManager][tid:2605] cust so dir name is /root/cust_aicpu_0_0_2605/.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.028.039 [raw_device.cc:346] 2605 Init: isAddrFlat:0
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.375 [grp_mng.c:81][bufmng] [halGrpCreate 81] Create grp. (grp_name=private_buff_grp_2605; grp_id=1; max_size=0; cache_flag=0)
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.496 [grp_mng.c:144][bufmng] [halGrpAddProc 144] add grp succ, name:private_buff_grp_2605, pid:2605, grp_id:1, admin:1 alloc:1 read:1 write:1
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.732 [buff_recycle.c:758][bufmng] [procMngInit 758] poolId 1 add task node uid 2 pid 2605
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.820 [drv_buff_mbuf.c:65][bufmng] [mbufSetPrivFlag 65] Set mbuf priv flag sucess. (flag=0, g_mbuf_priv_flag=0)
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.832 [grp_mng.c:212][bufmng] [halGrpAttach 212] grp attach, grp_name:private_buff_grp_2605, grp_id:1, timeout:1000
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.952 [drv_buff_memzone.c:450][bufmng] [memzone_cfg 450] BuffCfg success. (cfg num=4; huge_prior=393216; normal=393216; huge_only=393216; dvpp_huge_prior=393216; dvpp_normal=393216; dvpp_huge_only=393216)
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:19.031.185 [tsd_client.cpp:189][TsdCapabilityGet][tid:2605] TsdCapabilityGet Begin.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.031.308 [engine.cc:78] 2605 Engine: Constructor.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.031.452 [stars_engine.cc:51] 2605 StarsEngine: Constructor.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.038.806 [npu_driver.cc:6306] 2605 GetDeviceStatus: GetDeviceStatus status=1.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.039.022 [device_error_proc.cc:446] 2605 GetTschCapability: Tsch not support capability feature, use old solution.
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:19.039.128 [client_manager.cpp:196][SetProfilingCallback][tid:2605] [TsdClient] set profiling callback success
[INFO] Set device[0] success
[INFO] Get RunMode[0] success
[INFO] Init resource success
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.055.546 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.055.892 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.056.124 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.056.264 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.056.414 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.056.536 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[INFO] Read file ../input/input_a.bin success, size 24
[INFO] Read file ../input/input_b.bin success, size 30
[INFO] Set input success
[INFO] Copy input[0] success
[INFO] Copy input[1] success
[INFO] Create stream success
[INFO] Execute aclnnMatrixMultiplyCustomGetWorkspaceSize success, workspace size 0
[INFO] Execute aclnnMatrixMultiplyCustom success
[INFO] Synchronize stream success
[INFO] Copy output[0] success
[INFO] Write file ../output/output_c.bin success, size 40
[INFO] Write output success
[INFO] Run op success
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.501.213 [aicpusd_cust_so_manager.cpp:401][DeleteCustSoDir][tid:2605] Access cust so dir /root/cust_aicpu_0_0_2605/ failed, error is No such file or directory.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.501.237 [dump_task.cpp:1941][ClearResource][tid:2605] clear all resource of data dump
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.501.355 [aicpusd_interface.cpp:229][StopAICPUScheduler][tid:2605] Success to stop aicpu scheduler, deviceId[0], hostPid[2605].
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.502.448 [stars_engine.cc:58] 2605 ~StarsEngine: Destructor.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.502.468 [engine.cc:84] 2605 ~Engine: Destructor.
[INFO] Reset Device success
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:19.503.095 [msprof_callback_impl.cpp:110] >>> (tid:2605) MsprofCtrlCallback called, type: 3
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:19.503.174 [ai_drv_dev_api.cpp:333] >>> (tid:2605) Succeeded to DrvGetApiVersion version: 0x71f0d
[INFO] Destroy resource success
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.506.508 [aicpusd_worker.cpp:168][WaitForStop][tid:2605] WaitForStop begin.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:22.199.586 [aicpusd_worker.cpp:174][WaitForStop][tid:2605] WaitForStop end.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:22.205.905 [aicpusd_mpi_mgr.cpp:48][PrintStatisticInfo][tid:2605] Mpi Dvpp event statistic: [0]
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:22.488.006 [runtime.cc:1540] 2605 ~Runtime: deconstruct runtime
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:22.488.040 [runtime.cc:1547] 2605 ~Runtime: wait monitor success, use=0.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:22.540.523 [task_fail_callback_data_manager.cc:63] 2605 ~TaskFailCallBackManager: Destructor.
INFO: acl executable run success!
Output shape: (4, 5)
Golden shape: (4, 5)
Output (first 2x2):
[[0. 0.]
[0. 0.]]
Golden (first 2x2):
[[ 0.4927 -1.062 ]
[ 0.05502 -0.411 ]]
Total elements: 20
Different elements: 20
data[0,0]: expected=0.492676, actual=0.000000, diff=0.492676, rdiff=1.000000
data[0,0]: expected=0.492676, actual=0.000000, diff=0.492676, rdiff=1.000000
data[0,0]: expected=0.492676, actual=0.000000, diff=0.492676, rdiff=1.000000
data[0,0]: expected=0.492676, actual=0.000000, diff=0.492676, rdiff=1.000000
data[0,0]: expected=0.492676, actual=0.000000, diff=0.492676, rdiff=1.000000
data[0,1]: expected=-1.061523, actual=0.000000, diff=1.061523, rdiff=1.000000
data[0,1]: expected=-1.061523, actual=0.000000, diff=1.061523, rdiff=1.000000
data[0,1]: expected=-1.061523, actual=0.000000, diff=1.061523, rdiff=1.000000
data[0,1]: expected=-1.061523, actual=0.000000, diff=1.061523, rdiff=1.000000
data[0,1]: expected=-1.061523, actual=0.000000, diff=1.061523, rdiff=1.000000
error ratio: 1.0000, tolerance: 0.0010
[ERROR] result error
ERROR: verify result failed!
点赞
收藏
回复
分享
举报
已解决
INFO: generate input data success!
-- The C compiler identification is GNU 10.3.1
-- The CXX compiler identification is GNU 10.3.1
-- Detecting C compiler ABI info
-- Detecting C compiler ABI info - done
-- Check for working C compiler: /usr/bin/cc - skipped
-- Detecting C compile features
-- Detecting C compile features - done
-- Detecting CXX compiler ABI info
-- Detecting CXX compiler ABI info - done
-- Check for working CXX compiler: /usr/bin/c++ - skipped
-- Detecting CXX compile features
-- Detecting CXX compile features - done
-- env INC_PATH: /usr/local/Ascend/ascend-toolkit/latest
-- env LIB_PATH: /usr/local/Ascend/ascend-toolkit/latest/aarch64-linux/devlib
-- Configuring done
-- Generating done
-- Build files have been written to: /home/HwHiAiUser/workspace/CustomOperators/DeltaHiddenCustom/MatmulTest/MatrixMultiplyInvocation/build
INFO: cmake success!
[ 20%] Building CXX object CMakeFiles/execute_matmul_op.dir/operator_desc.cpp.o
[ 40%] Building CXX object CMakeFiles/execute_matmul_op.dir/op_runner.cpp.o
[ 60%] Building CXX object CMakeFiles/execute_matmul_op.dir/main.cpp.o
[ 80%] Building CXX object CMakeFiles/execute_matmul_op.dir/common.cpp.o
[100%] Linking CXX executable /home/HwHiAiUser/workspace/CustomOperators/DeltaHiddenCustom/MatmulTest/MatrixMultiplyInvocation/output/execute_matmul_op
[100%] Built target execute_matmul_op
INFO: make success!
INFO: execute op!
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:12.514.803 [task_fail_callback_data_manager.cc:58] 2605 TaskFailCallBackManager: Constructor.
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.363.276 [msprof_callback_impl.cpp:358] >>> (tid:2605) Started to register profiling ctrl callback.
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.365.355 [msprof_callback_impl.cpp:365] >>> (tid:2605) Started to register profiling hash id callback.
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.365.374 [prof_atls_plugin.cpp:117] (tid:2605) RegisterProfileCallback, callback type is 7
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.365.467 [msprof_callback_impl.cpp:372] >>> (tid:2605) Started to register profiling enable host freq callback.
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.365.541 [prof_atls_plugin.cpp:117] (tid:2605) RegisterProfileCallback, callback type is 8
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.453.324 [prof_atls_plugin.cpp:210] (tid:2605) Module[61] register callback of ctrl handle.
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:13.497.235 [prof_atls_plugin.cpp:210] (tid:2605) Module[45] register callback of ctrl handle.
[INFO] GE(2605,execute_matmul_op):2025-08-04-02:30:14.297.339 [op_tiling_manager.cc:109]2605 ~FuncPerfScope:[GEPERFTRACE] The time cost of OpTilingManager::LoadSo is [799877] micro seconds.
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:14.980.569 [prof_atls_plugin.cpp:210] (tid:2605) Module[6] register callback of ctrl handle.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:18.321.023 [runtime_keeper.cc:149] 2605 CreateRuntimeImpl: Open libruntime_v100.so success
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:18.322.717 [runtime.cc:5060] 2605 GetVisibleDevices: ASCEND_RT_VISIBLE_DEVICES param was not set
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:18.378.120 [prof_atls_plugin.cpp:210] (tid:2605) Module[7] register callback of ctrl handle.
[INFO] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:18.380.388 [prof_atls_plugin.cpp:210] (tid:2605) Module[48] register callback of ctrl handle.
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:18.380.528 [msprof_callback_impl.cpp:110] >>> (tid:2605) MsprofCtrlCallback called, type: 255
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:18.383.541 [ai_drv_dev_api.cpp:333] >>> (tid:2605) Succeeded to DrvGetApiVersion version: 0x71f0d
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.386.674 [client_manager.cpp:464][GetClientRunMode][tid:2605] runningMode:0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.386.716 [client_manager.cpp:127][GetInstance][tid:2605] [ClientManager] Current mode:2
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.386.883 [thread_mode_manager.cpp:70][Open][tid:2605] [ThreadModeManager] enter into open process deviceId[0] rankSize[0]
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.182 [package_worker.cpp:23][RuntimePackageWorker][tid:2605] Start init RuntimePackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.298 [package_worker.cpp:23][DshapePackageWorker][tid:2605] Start init DshapePackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.367 [package_worker.cpp:23][OmPackageWorker][tid:2605] Start init OmPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.426 [package_worker.cpp:30][AicpuProcessPackageWorker][tid:2605] Start init AicpuProcessPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.486 [package_worker.cpp:30][AicpuProcessPackageWorker][tid:2605] Start init AicpuProcessPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.536 [package_worker.cpp:76][ExtendProcessPackageWorker][tid:2605] Start init ExtendProcessPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.593 [package_worker.cpp:28][AicpuThreadPackageWorker][tid:2605] Start init AicpuThreadPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.655 [package_worker.cpp:28][AicpuThreadPackageWorker][tid:2605] Start init AicpuThreadPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.706 [package_worker.cpp:62][ExtendThreadPackageWorker][tid:2605] Start init ExtendThreadPackageWorker. Package worker paras, deviceId=0, vfId=0
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.843 [aicpu_thread_package_worker.cpp:132][OpenVerifyFile][tid:2605] Create verify file end, path=/root/aicpu_package_install.info, reason=File exists
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.388.946 [aicpu_thread_package_worker.cpp:141][OpenVerifyFile][tid:2605] Create or open verify file success, path=/root/aicpu_package_install.info
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.389.586 [aicpu_thread_package_worker.cpp:132][OpenVerifyFile][tid:2605] Create verify file end, path=/root/extend_aicpu_package_install.info, reason=File exists
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.389.676 [aicpu_thread_package_worker.cpp:141][OpenVerifyFile][tid:2605] Create or open verify file success, path=/root/extend_aicpu_package_install.info
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:18.983.354 [thread_mode_manager.cpp:158][SetAICPUProfilingCallback][tid:2605] [ThreadModeManager] profiling callback is nullptr, skip set aicpu profiling callback
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.983.392 [aicpusd_interface_process.cpp:524][TryGetLogLevelFromParentProcess][tid:2605] get ASCEND_GLOBAL_LOG_LEVEL [3] and ASCEND_GLOBAL_EVENT_ENABLE []
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.220 [aicpusd_interface_process.cpp:466][GetCurrentRunMode][tid:2605] Current aicpu mode is offline (call by api).
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.359 [aicpusd_drv_manager.cpp:327][MarkMdc][tid:2605] Get hardware version[7] success.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.445 [aicpusd_drv_manager.cpp:190][GetNormalAicpuInfo][tid:2605] aicpuBitMap[6], aicpuNum[2].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.519 [aicpusd_drv_manager.cpp:224][GetCcpuInfo][tid:2605] ccpuBitMap[3].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.622 [aicpusd_drv_manager.cpp:110][GetNormalAicpuDCpuInfo][tid:2605] GetNormalAicpuDCpuInfo, deviceId[0], aicpu_num[2], aicpu_os_sched[281470681743361], ccpu_num[255082402676737], ccpu_os_sched[255082402676737], dcpu_num[255082402676736], dcpu_os_sched[281470681743361], tscpu_num[0], tscpu_os_sched[0].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.638 [aicpusd_drv_manager.cpp:306][InitDrvMgrCaluniqueVfId][tid:2605] InitDrvMgr uniqueVfId=0, deviceId=0
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.716 [aicpusd_drv_manager.cpp:377][InitDrvMgr][tid:2605] host pid[2605], host proc name[], vf id[0], first aicpu index[0], aicpu num[2], dcpu base index[1], dcpu num[0].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.984.958 [aicpusd_resource_manager.cpp:247][InitBufManager][tid:2605] Aicpu schedule SetBuffCfg successed!
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.985.517 [aicpusd_worker.cpp:74][ThreadPool][tid:2605] ThreadPool
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.985.951 [aicpusd_worker.cpp:274][AddPidToTask][tid:2610] Bind pid by hal.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.985.966 [aicpusd_worker.cpp:276][AddPidToTask][tid:2610] AddPidToTask by halBindCgroup
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.986.178 [aicpusd_worker.cpp:274][AddPidToTask][tid:2609] Bind pid by hal.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:18.986.191 [aicpusd_worker.cpp:276][AddPidToTask][tid:2609] AddPidToTask by halBindCgroup
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.023.577 [aicpusd_worker.cpp:323][SetAffinityBySelf][tid:2610] [hw]SetAffinityBySelf, physIndex[2], devNum[0]
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.023.624 [aicpusd_worker.cpp:323][SetAffinityBySelf][tid:2609] [hw]SetAffinityBySelf, physIndex[1], devNum[0]
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.023.626 [aicpusd_worker.cpp:389][SetAffinity][tid:2610] aicpu bind tid by self, index[1], deviceId[0], res[0].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.023.639 [aicpusd_worker.cpp:389][SetAffinity][tid:2609] aicpu bind tid by self, index[0], deviceId[0], res[0].
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.023.958 [aicpusd_cust_so_manager.cpp:77][InitAicpuCustSoManager][tid:2605] cust so dir name is /root/cust_aicpu_0_0_2605/.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.028.039 [raw_device.cc:346] 2605 Init: isAddrFlat:0
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.375 [grp_mng.c:81][bufmng] [halGrpCreate 81] Create grp. (grp_name=private_buff_grp_2605; grp_id=1; max_size=0; cache_flag=0)
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.496 [grp_mng.c:144][bufmng] [halGrpAddProc 144] add grp succ, name:private_buff_grp_2605, pid:2605, grp_id:1, admin:1 alloc:1 read:1 write:1
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.732 [buff_recycle.c:758][bufmng] [procMngInit 758] poolId 1 add task node uid 2 pid 2605
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.820 [drv_buff_mbuf.c:65][bufmng] [mbufSetPrivFlag 65] Set mbuf priv flag sucess. (flag=0, g_mbuf_priv_flag=0)
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.832 [grp_mng.c:212][bufmng] [halGrpAttach 212] grp attach, grp_name:private_buff_grp_2605, grp_id:1, timeout:1000
[EVENT] DRV(2605,execute_matmul_op):2025-08-04-02:30:19.028.952 [drv_buff_memzone.c:450][bufmng] [memzone_cfg 450] BuffCfg success. (cfg num=4; huge_prior=393216; normal=393216; huge_only=393216; dvpp_huge_prior=393216; dvpp_normal=393216; dvpp_huge_only=393216)
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:19.031.185 [tsd_client.cpp:189][TsdCapabilityGet][tid:2605] TsdCapabilityGet Begin.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.031.308 [engine.cc:78] 2605 Engine: Constructor.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.031.452 [stars_engine.cc:51] 2605 StarsEngine: Constructor.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.038.806 [npu_driver.cc:6306] 2605 GetDeviceStatus: GetDeviceStatus status=1.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.039.022 [device_error_proc.cc:446] 2605 GetTschCapability: Tsch not support capability feature, use old solution.
[INFO] TDT(2605,execute_matmul_op):2025-08-04-02:30:19.039.128 [client_manager.cpp:196][SetProfilingCallback][tid:2605] [TsdClient] set profiling callback success
[INFO] Set device[0] success
[INFO] Get RunMode[0] success
[INFO] Init resource success
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.055.546 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.055.892 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.056.124 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.056.264 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.056.414 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[ERROR] ASCENDCL(2605,execute_matmul_op):2025-08-04-02:30:19.056.536 [tensor_desc_internal.cpp:462]2605 aclGetTensorDescDimV2: [Check][Index]index out of range. index = 2, numDims = 2
[INFO] Read file ../input/input_a.bin success, size 24
[INFO] Read file ../input/input_b.bin success, size 30
[INFO] Set input success
[INFO] Copy input[0] success
[INFO] Copy input[1] success
[INFO] Create stream success
[INFO] Execute aclnnMatrixMultiplyCustomGetWorkspaceSize success, workspace size 0
[INFO] Execute aclnnMatrixMultiplyCustom success
[INFO] Synchronize stream success
[INFO] Copy output[0] success
[INFO] Write file ../output/output_c.bin success, size 40
[INFO] Write output success
[INFO] Run op success
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.501.213 [aicpusd_cust_so_manager.cpp:401][DeleteCustSoDir][tid:2605] Access cust so dir /root/cust_aicpu_0_0_2605/ failed, error is No such file or directory.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.501.237 [dump_task.cpp:1941][ClearResource][tid:2605] clear all resource of data dump
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.501.355 [aicpusd_interface.cpp:229][StopAICPUScheduler][tid:2605] Success to stop aicpu scheduler, deviceId[0], hostPid[2605].
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.502.448 [stars_engine.cc:58] 2605 ~StarsEngine: Destructor.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:19.502.468 [engine.cc:84] 2605 ~Engine: Destructor.
[INFO] Reset Device success
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:19.503.095 [msprof_callback_impl.cpp:110] >>> (tid:2605) MsprofCtrlCallback called, type: 3
[EVENT] PROFILING(2605,execute_matmul_op):2025-08-04-02:30:19.503.174 [ai_drv_dev_api.cpp:333] >>> (tid:2605) Succeeded to DrvGetApiVersion version: 0x71f0d
[INFO] Destroy resource success
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:19.506.508 [aicpusd_worker.cpp:168][WaitForStop][tid:2605] WaitForStop begin.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:22.199.586 [aicpusd_worker.cpp:174][WaitForStop][tid:2605] WaitForStop end.
[EVENT] CCECPU(2605,execute_matmul_op):2025-08-04-02:30:22.205.905 [aicpusd_mpi_mgr.cpp:48][PrintStatisticInfo][tid:2605] Mpi Dvpp event statistic: [0]
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:22.488.006 [runtime.cc:1540] 2605 ~Runtime: deconstruct runtime
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:22.488.040 [runtime.cc:1547] 2605 ~Runtime: wait monitor success, use=0.
[INFO] RUNTIME(2605,execute_matmul_op):2025-08-04-02:30:22.540.523 [task_fail_callback_data_manager.cc:63] 2605 ~TaskFailCallBackManager: Destructor.
INFO: acl executable run success!
Output shape: (4, 5)
Golden shape: (4, 5)
Output (first 2x2):
[[0. 0.]
[0. 0.]]
Golden (first 2x2):
[[ 0.4927 -1.062 ]
[ 0.05502 -0.411 ]]
Total elements: 20
Different elements: 20
data[0,0]: expected=0.492676, actual=0.000000, diff=0.492676, rdiff=1.000000
data[0,0]: expected=0.492676, actual=0.000000, diff=0.492676, rdiff=1.000000
data[0,0]: expected=0.492676, actual=0.000000, diff=0.492676, rdiff=1.000000
data[0,0]: expected=0.492676, actual=0.000000, diff=0.492676, rdiff=1.000000
data[0,0]: expected=0.492676, actual=0.000000, diff=0.492676, rdiff=1.000000
data[0,1]: expected=-1.061523, actual=0.000000, diff=1.061523, rdiff=1.000000
data[0,1]: expected=-1.061523, actual=0.000000, diff=1.061523, rdiff=1.000000
data[0,1]: expected=-1.061523, actual=0.000000, diff=1.061523, rdiff=1.000000
data[0,1]: expected=-1.061523, actual=0.000000, diff=1.061523, rdiff=1.000000
data[0,1]: expected=-1.061523, actual=0.000000, diff=1.061523, rdiff=1.000000
error ratio: 1.0000, tolerance: 0.0010
[ERROR] result error
ERROR: verify result failed!