Star105
83
代码
代码
Issues2
Pull Requests4
Actions
项目讨论
Wiki
分析
Star105
83
已关闭
[Bug] mindie镜像拉起服务化，按资料采集服务化调优信息后，解析报错 #58
yejingjing创建于  5月21日关闭于  5月26日
yejingjing
yejingjing成员
5月21日 创建

👉 遇到问题先看这里

🌟 第一次使用工具遇到问题？

按🚀 快速入门

❓ 搜索历史issue，查看冷门的同类问题

在🔖 Issue中搜索历史类似问题

操作系统及版本

Ubuntu 24.04.4 LTS

python版本

3.11

MsServiceProfiler 工具版本

社区下载https://www.hiascend.com/developer/software/mindstudio/download?versionId=142&ids=45%2C26958bcc909e4cd48fa56d4c4a43ebec%2C85%2C50

是否必现

是

MsServiceProfiler 执行命令

python3 -m ms_service_profiler.parse --input-path=/home/yejingjing/.ms_server_profiler/

预期行为

执行成功无报错

实际行为

1、创建容器，配置环境变量export SERVICE_PROF_CONFIG_PATH="./ms_service_profiler_config.json"
2、拉起服务化，然后修改json开关=1，此时发现已经有落盘文件，然后修改json开关=0

# 配置CANN环境，默认安装在/usr/local目录下
source /usr/local/Ascend/ascend-toolkit/set_env.sh
# 配置加速库环境
source /usr/local/Ascend/nnal/atb/set_env.sh
# 配置模型仓环境变量
source /usr/local/Ascend/atb-models/set_env.sh
# MindIE
source /usr/local/Ascend/mindie/latest/mindie-llm/set_env.sh
source /usr/local/Ascend/mindie/latest/mindie-service/set_env.sh
# 开启MindIE日志打印
export MINDIE_LOG_TO_STDOUT="true"
root@localhost:/usr/local/Ascend/mindie/latest/mindie-service# ./bin/mindieservice_daemon

3、其他依赖版本符合要求，只修改pip install pandas~=2.2

root@localhost:/usr/local/Ascend/mindie/latest/mindie-service# pip install pandas~=2.2
root@localhost:/usr/local/Ascend/mindie/latest/mindie-service# pip list|grep numpy
numpy                       1.26.4
root@localhost:/usr/local/Ascend/mindie/latest/mindie-service# pip list|grep psutil
psutil                      6.0.0

4、执行解析，发现报错

**********host:/home/yejingjing# ll /home/yejingjing/.ms_server_profiler/0520-0954/Trace_Service/
total 108
drwxr-xr-x. 2 root root  4096 May 21 09:45 ./
drwxr-x---. 3 root root  4096 May 20 10:00 ../
-rw-r-----. 1 root root 20480 May 21 09:42 ms_service_localhost.localdomain-6996.db
-rw-r-----. 1 root root 20480 May 21 09:42 ms_service_localhost.localdomain-7009.db
-rw-r-----. 1 root root 20480 May 21 09:42 ms_service_localhost.localdomain-7011.db
-rw-r-----. 1 root root 20480 May 21 09:42 ms_service_localhost.localdomain-7013.db
-rw-r-----. 1 root root 20480 May 21 09:42 ms_service_localhost.localdomain-7015.db

执行：

root@localhost:/usr/local/Ascend/mindie/latest/mindie-service# cat ms_service_profiler_config.json 
{
    "enable": 0,
    "prof_dir": "/home/yejingjing/.ms_server_profiler/",
    "profiler_level": "INFO",
    "acl_task_time": 0,
    "acl_prof_task_time_level": "",
    "timelimit": 0,
    "domain": ""
}
root@localhost:/usr/local/Ascend/mindie/latest/mindie-service# python3 -m ms_service_profiler.parse --input-path=/home/yejingjing/.ms_server_profiler/^C
root@localhost:/usr/local/Ascend/mindie/latest/mindie-service# cd /home/yejingjing/
root@localhost:/home/yejingjing# python3 -m ms_service_profiler.parse --input-path=/home/yejingjing/.ms_server_profiler/
2026-05-21 09:45:31,569 - 21007 - msServiceProfiler - WARNING - Security Warning: Do not run this tool as root. Running with elevated privileges may compromise system security. Use a regular user account.
2026-05-21 09:45:31,570 - 21007 - msServiceProfiler - INFO - Start to parse.
2026-05-21 09:45:31,596 - 21007 - msServiceProfiler - INFO - task [data_source:db] start. 
2026-05-21 09:45:31,604 - 21137 - msServiceProfiler - INFO - Using mstx logic for '/home/yejingjing/.ms_server_profiler/0520-0954/Trace_Service/ms_service_localhost.localdomain-7009.db'
2026-05-21 09:45:31,604 - 21136 - msServiceProfiler - INFO - Using mstx logic for '/home/yejingjing/.ms_server_profiler/0520-0954/Trace_Service/ms_service_localhost.localdomain-7011.db'
2026-05-21 09:45:31,604 - 21135 - msServiceProfiler - INFO - Using mstx logic for '/home/yejingjing/.ms_server_profiler/0520-0954/Trace_Service/ms_service_localhost.localdomain-7013.db'
2026-05-21 09:45:31,604 - 21138 - msServiceProfiler - INFO - Using mstx logic for '/home/yejingjing/.ms_server_profiler/0520-0954/Trace_Service/ms_service_localhost.localdomain-6996.db'
2026-05-21 09:45:31,604 - 21137 - msServiceProfiler - WARNING - cannot read prof data from '/home/yejingjing/.ms_server_profiler/0520-0954/Trace_Service/ms_service_localhost.localdomain-7009.db', due to Execution failed on sql 'SELECT markId,message,pid,tid,timestamp,endTimestamp FROM mstx order by markId': no such table: mstx
2026-05-21 09:45:31,604 - 21138 - msServiceProfiler - WARNING - cannot read prof data from '/home/yejingjing/.ms_server_profiler/0520-0954/Trace_Service/ms_service_localhost.localdomain-6996.db', due to Execution failed on sql 'SELECT markId,message,pid,tid,timestamp,endTimestamp FROM mstx order by markId': no such table: mstx
2026-05-21 09:45:31,604 - 21136 - msServiceProfiler - WARNING - cannot read prof data from '/home/yejingjing/.ms_server_profiler/0520-0954/Trace_Service/ms_service_localhost.localdomain-7011.db', due to Execution failed on sql 'SELECT markId,message,pid,tid,timestamp,endTimestamp FROM mstx order by markId': no such table: mstx
2026-05-21 09:45:31,604 - 21135 - msServiceProfiler - WARNING - cannot read prof data from '/home/yejingjing/.ms_server_profiler/0520-0954/Trace_Service/ms_service_localhost.localdomain-7013.db', due to Execution failed on sql 'SELECT markId,message,pid,tid,timestamp,endTimestamp FROM mstx order by markId': no such table: mstx
2026-05-21 09:45:31,604 - 21139 - msServiceProfiler - INFO - Using mstx logic for '/home/yejingjing/.ms_server_profiler/0520-0954/Trace_Service/ms_service_localhost.localdomain-7015.db'
2026-05-21 09:45:31,605 - 21139 - msServiceProfiler - WARNING - cannot read prof data from '/home/yejingjing/.ms_server_profiler/0520-0954/Trace_Service/ms_service_localhost.localdomain-7015.db', due to Execution failed on sql 'SELECT markId,message,pid,tid,timestamp,endTimestamp FROM mstx order by markId': no such table: mstx
2026-05-21 09:45:31,606 - 21007 - msServiceProfiler - INFO - task [data_source:db] finished.
2026-05-21 09:45:31,606 - 21007 - msServiceProfiler - INFO - Progress: 6.7% (1/15 tasks completed)
2026-05-21 09:45:31,607 - 21007 - msServiceProfiler - INFO - task [pipeline:service] start. 
2026-05-21 09:45:31,608 - 21135 - msServiceProfiler - WARNING - ignoring current process by default.: ('name', 'start_time', 'start_datetime') not exists.
2026-05-21 09:45:31,608 - 21137 - msServiceProfiler - WARNING - ignoring current process by default.: ('name', 'start_time', 'start_datetime') not exists.
2026-05-21 09:45:31,608 - 21138 - msServiceProfiler - WARNING - ignoring current process by default.: ('name', 'start_time', 'start_datetime') not exists.
2026-05-21 09:45:31,608 - 21139 - msServiceProfiler - WARNING - ignoring current process by default.: ('name', 'start_time', 'start_datetime') not exists.
2026-05-21 09:45:31,608 - 21136 - msServiceProfiler - WARNING - ignoring current process by default.: ('name', 'start_time', 'start_datetime') not exists.
2026-05-21 09:45:31,611 - 21138 - msServiceProfiler - WARNING - ignoring current process by default.: ('token_id_list',) not exists.
2026-05-21 09:45:31,611 - 21139 - msServiceProfiler - WARNING - ignoring current process by default.: ('token_id_list',) not exists.
2026-05-21 09:45:31,611 - 21137 - msServiceProfiler - WARNING - ignoring current process by default.: ('token_id_list',) not exists.
2026-05-21 09:45:31,611 - 21137 - msServiceProfiler - WARNING - No transaction data found for KVCache metrics calculation
2026-05-21 09:45:31,611 - 21138 - msServiceProfiler - WARNING - No transaction data found for KVCache metrics calculation
2026-05-21 09:45:31,611 - 21139 - msServiceProfiler - WARNING - No transaction data found for KVCache metrics calculation
2026-05-21 09:45:31,611 - 21136 - msServiceProfiler - WARNING - ignoring current process by default.: ('token_id_list',) not exists.
2026-05-21 09:45:31,611 - 21135 - msServiceProfiler - WARNING - ignoring current process by default.: ('token_id_list',) not exists.
2026-05-21 09:45:31,611 - 21136 - msServiceProfiler - WARNING - No transaction data found for KVCache metrics calculation
2026-05-21 09:45:31,611 - 21135 - msServiceProfiler - WARNING - No transaction data found for KVCache metrics calculation
2026-05-21 09:45:31,616 - 21135 - msServiceProfiler - ERROR - plugin_concat-0 failure. Program stopped.
Traceback (most recent call last):
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/pipeline/pipeline_base.py", line 32, in run_step
    data = processor.parse(data, *more_params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/utils/timer.py", line 36, in wrapper
    result = func(*args, **kwargs)  # 执行函数
             ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/plugins/plugin_concat.py", line 315, in parse
    merged_data[key] = value.sort_values(by='start_time', ascending=True).reset_index(drop=True)
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pandas/core/frame.py", line 7211, in sort_values
    k = self._get_label_or_level_values(by[0], axis=axis)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pandas/core/generic.py", line 1914, in _get_label_or_level_values
    raise KeyError(key)
KeyError: 'start_time'
2026-05-21 09:45:31,622 - 21007 - msServiceProfiler - ERROR - task [pipeline:service] error. due to ParseError: plugin_concat-0 failure. Program stopped. 'start_time' 
2026-05-21 09:45:31,622 - 21007 - msServiceProfiler - INFO - Progress: 13.3% (2/15 tasks completed, 1 tasks failed)
2026-05-21 09:45:31,623 - 21007 - msServiceProfiler - INFO - task [pipeline:eplb_observe] start. 
2026-05-21 09:45:31,623 - 21135 - msServiceProfiler - ERROR - pipeline:service-0 error. ParseError: plugin_concat-0 failure. Program stopped. 'start_time'
Traceback (most recent call last):
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/pipeline/pipeline_base.py", line 32, in run_step
    data = processor.parse(data, *more_params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/utils/timer.py", line 36, in wrapper
    result = func(*args, **kwargs)  # 执行函数
             ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/plugins/plugin_concat.py", line 315, in parse
    merged_data[key] = value.sort_values(by='start_time', ascending=True).reset_index(drop=True)
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pandas/core/frame.py", line 7211, in sort_values
    k = self._get_label_or_level_values(by[0], axis=axis)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pandas/core/generic.py", line 1914, in _get_label_or_level_values
    raise KeyError(key)
KeyError: 'start_time'

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/task/task_manager.py", line 333, in task_run
    task_res = task_ins.run()
               ^^^^^^^^^^^^^^
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/pipeline/pipeline_service.py", line 62, in run
    data = self.run_step(PluginConcat, PluginConcat.name, data_list)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/pipeline/pipeline_base.py", line 39, in run_step
    raise ParseError(f'{name}-{self.task_index} failure. Program stopped. {str(ex)}') from ex
ms_service_profiler.utils.error.ParseError: ParseError: plugin_concat-0 failure. Program stopped. 'start_time'
2026-05-21 09:45:31,626 - 21135 - msServiceProfiler - ERROR - ProcessorEplbObserve-0 failure. Skip it.
Traceback (most recent call last):
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/pipeline/pipeline_base.py", line 32, in run_step
    data = processor.parse(data, *more_params)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/processor/processor_eplb_observe.py", line 40, in parse
    tx_data_df = pd.concat(data)
                 ^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pandas/core/reshape/concat.py", line 382, in concat
    op = _Concatenator(
         ^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pandas/core/reshape/concat.py", line 445, in __init__
    objs, keys = self._clean_keys_and_objs(objs, keys)
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/pandas/core/reshape/concat.py", line 507, in _clean_keys_and_objs
    raise ValueError("No objects to concatenate")
ValueError: No objects to concatenate
2026-05-21 09:45:31,627 - 21007 - msServiceProfiler - INFO - task [pipeline:eplb_observe] finished.
2026-05-21 09:45:31,627 - 21007 - msServiceProfiler - INFO - Progress: 20.0% (3/15 tasks completed, 1 tasks failed)
2026-05-21 09:45:31,627 - 21007 - msServiceProfiler - INFO - task [trace] start. 
2026-05-21 09:45:31,628 - 21007 - msServiceProfiler - INFO - task [req_status] start. 
2026-05-21 09:45:31,629 - 21007 - msServiceProfiler - INFO - task [req_data] start. 
2026-05-21 09:45:31,629 - 21007 - msServiceProfiler - INFO - task [batch_data] start. 
2026-05-21 09:45:31,630 - 21007 - msServiceProfiler - INFO - task [kvcache_data] start. 
2026-05-21 09:45:31,631 - 21007 - msServiceProfiler - INFO - task [latency] start. 
2026-05-21 09:45:31,631 - 21007 - msServiceProfiler - INFO - task [pd_comm] start. 
2026-05-21 09:45:31,632 - 21007 - msServiceProfiler - INFO - task [forward_data] start. 
2026-05-21 09:45:31,633 - 21007 - msServiceProfiler - INFO - task [coordinator] start. 
2026-05-21 09:45:31,633 - 21007 - msServiceProfiler - INFO - task [op_summary_copier] start. 
2026-05-21 09:45:31,634 - 21007 - msServiceProfiler - INFO - task [statistic] start. 
2026-05-21 09:45:31,635 - 21007 - msServiceProfiler - INFO - task [expert_hot] start. 
2026-05-21 09:45:31,635 - 21007 - msServiceProfiler - ERROR - task [expert_hot] error. due to 'list' object has no attribute 'keys' 
2026-05-21 09:45:31,635 - 21007 - msServiceProfiler - INFO - Progress: 26.7% (4/15 tasks completed, 2 tasks failed)
2026-05-21 09:45:31,636 - 21007 - msServiceProfiler - INFO - Exporter done.
2026-05-21 09:45:31,637 - 21135 - msServiceProfiler - ERROR - expert_hot-0 error. 'list' object has no attribute 'keys'
Traceback (most recent call last):
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/task/task_manager.py", line 333, in task_run
    task_res = task_ins.run()
               ^^^^^^^^^^^^^^
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/exporters/base.py", line 39, in run
    self.do_export()
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/exporters/exporter_eplb_observe.py", line 133, in do_export
    self.export(data)
  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/exporters/exporter_eplb_observe.py", line 51, in export
    if NAME not in data.keys() or not data.get(NAME):
                   ^^^^^^^^^
AttributeError: 'list' object has no attribute 'keys'

欢迎加入社区，感谢您对社区的贡献 🎉!

likedislike
yejingjingyejingjing成员
5月21日 关联了里程碑：MindStudio 26.1.0
yejingjingyejingjing成员
5月21日 添加了label：bug, high-priority
kai1949
kai1949成员
5月21日 评论：

/label add triaged
👋 您好,欢迎向 MindStudio-Service-Profiler 提交 Issue！
我们已收到您的反馈，感谢你对开源社区的支持。🎉

📅处理时效： 维护团队将在24小时内 查看并回复您的问题（工作日）。
🔍自助查询： 在等待期间，建议您先查阅以下资料，可能已有解决方案：

📖 MindStudio-Service-Profiler官方文档
📝 贡献者指南

请确保 Issue 描述清晰，包含复现步骤和日志，这将帮助我们更快定位问题。谢谢！

likedislike
ascend-robotascend-robot成员
5月21日 添加了label：triaged
yejingjingyejingjing成员
5月21日 修改了issue 的描述
yejingjingyejingjing成员
5月21日 修改了issue 的描述
yejingjingyejingjing成员
5月21日 修改了issue 的描述
yejingjing
yejingjing成员
5月21日 评论：

确认有推理请求的情况下，解析正常，问题级别为一般

likedislike
yejingjingyejingjing成员
5月21日 添加了label：medium-priority；删除了label：high-priority
H
hewenbo成员
5月21日 评论：

解析部分日志逻辑可能需优化。和SE对齐后再确认是否修改和如何修改。

likedislike
H
hewenbo成员
5月26日 评论：

/label add resolved

likedislike
ascend-robotascend-robot成员
5月26日 添加了label：resolved
Hhewenbo成员
5月26日 关联了pull request：【msserviceprofiler_master】当profiling数据为空时，优化日志打印
yejingjing
yejingjing成员
5月26日 评论：

确认修改后，当采集结果无推理请求时工具给出报错提示

  File "/usr/local/Ascend/ascend-toolkit/latest/python/site-packages/ms_service_profiler/processor/processor_eplb_observe.py", line 40, in parse
    raise ValueError("Profiling data is invalid, please check the profiling data.")
ValueError: Profiling data is invalid, please check the profiling data.

，有推理请求时成功解析无报错

likedislike
yejingjingyejingjing成员
5月26日 issue状态由 TODO 改变为 DONE
yejingjingyejingjing成员
5月26日 关闭了 issue