EngineX/xc-llm-kunlun
3
0
Fork 0
Code Issues Pull Requests Actions Projects Releases Wiki Activity

Initial commit for vLLM-Kunlun Plugin

Browse Source
This commit is contained in:
dongxinyu03
2025-12-10 12:05:39 +08:00
commit c728e52505
131 changed files with 28816 additions and 0 deletions
Download Patch File Download Diff File Expand all files Collapse all files

7
docs/source/developer_guide/performance/index.md Normal file
View File

@@ -0,0 +1,7 @@
# Performance
:::{toctree}
:caption: Performance
:maxdepth: 1
performance_benchmark/index
:::

147
docs/source/developer_guide/performance/performance_benchmark/benchmark_kernel.md Normal file
View File

@@ -0,0 +1,147 @@
## Operator performance
### XProfiler
#### 1.Download and install
- The download link for the x86_64 platform installation package xre-Linux-x86_64 is:
`https://klx-sdk-release-public.su.bcebos.com/xre/kl3-release/5.0.21.26/peermem/xre-Linux-x86_64-5.0.21.26.run`
`https://klx-sdk-release-public.su.bcebos.com/xre/kl3-release/5.0.21.26/peermem/xre-Linux-x86_64-5.0.21.26.tar.gz`
- If the client is using bdCentOS, we recommend using the following download link:
`https://klx-sdk-release-public.su.bcebos.com/xre/kl3-release/5.0.21.26/xre-bdcentos-x86_64-5.0.21.26.tar.gz`
After downloading and extracting, you can directly execute `xpu-installer` and `install_rt.sh` to install.
#### 2.Start using
XProfiler supports three modes: 1) fork mode; 2) time mode; and 3) daemon mode. After execution, XProfiler will generate two types of JSON files:
- xprofiler.settings.json: Records the event configuration for this trace.
- xprofiler.trace.json: Records the results of this trace.
The specific modes will be introduced below.
##### fork mode
The fork pattern is used to track the entire time period from the start to the end of a user program. This pattern is suitable for most inference tasks and is the simplest to use. An example is shown below:
```bash
/xxxx/xxxx/xprofiler -r500 --xpu=0 python test.py
```
- --r: Sets the trace time resolution in nanoseconds (ns). The default is 100. If an "out of space error" occurs, try increasing the -r value to 500.
- --xpu: Specifies the acquisition device ID, supporting multi-card configuration. --xpu=all enables all cards; the default is card 0.
More parameters can be found in the command-line parameters section later.
##### time mode
The time mode is used to track user programs for a period of time. This method is suitable for tasks that need to run for a long time.
Using the -t or --time command-line parameter, XPorfiler will run for the specified time and then exit, in seconds. In this mode, the application needs to be started separately. An example is as follows:
(1) Starting XPorfiler
```bash
/xxxx/xxxx/xprofiler -r 500 --xpu=0 -t600 # Time mode collects events within a specified time period, measured in seconds (s).
```
A temporary .sock file will be generated in the execution directory. The path needs to be configured in the environment variables.
(2) Start the program
```bash
export XPU_ENABLE_PROFILER_TRACING=1
export XPU_TRACING_OUTPUT_NAME=<xprofiler execution directory>/xprofiler.sock
# Start your own program
python xxx.py
```
##### deamon mode
The daemon mode is used to track the event timeline of a specified code segment, eliminating interference from redundant information. The startup command is the same as in fork mode.
(1) Insert start and stop interfaces.
```python
import xtorch_ops
# Only capture events during the generate phase
xtorch_ops.kunlun_profiler_start()
outputs = llm.generate(
inputs,
sampling_params=sampling_params,
lora_request=lora_request,
)
xtorch_ops.kunlun_profiler_end()
```
(2) Launch X profiler in a terminal
```python
# Specify the output file as the trace_output file in the current path.
/xxxx/xxxx/xprofiler-Linux_x86_64-2.0.2.0/bin/xprofiler -r 500 --xpu=0 -e ./trace_output -d
```
After startup, a .sock file will be generated in the current directory.
```bash
xprofiler.sock
```
(3) Launch your own program on another terminal.
```python
export XPU_ENABLE_PROFILER_TRACING=1
# Here, the path to the .sock file from step 2 is used for assignment.
export XPU_TRACING_OUTPUT_NAME=<xprofiler execution directory>/xprofiler.sock
# Start your own program
python xxx.py
```
Note: If you want to specify a particular card to run on, you must import the XPU_VISIBLE_DEVICES environment variable in the terminal in steps 2 and 3; otherwise, you will not be able to capture the data.
##### More parameters
| parameters | Example | default value | describe |
| -------------------------- | --------------------------------------- | ------------- | -------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- |
| -b or --buffer-size | -b=512 | 256 | Specifies the size of the trace buffer in MB. This is generally not required. However, if there are many trace signals, the buffer size can be increased appropriately to avoid OOS (Out of Size). |
| -x or --xpu | -x=0--xpu=0 | 0 | Set the card number to be tracked; multiple cards or all cards can be set. |
| -t or --time | -t=10 | off | Enable time mode, in seconds, to capture information over a specified period. |
| -d or --deamonize | -r500 | 0 | Enable daemon mode to retrieve events in the background. |
| -r or --export-profile | -e ./trace_output-e ./output/trace.json | ./ | Record the trace results to a document or folder. If this parameter is not specified, a default xprofiler.trace.json file will be generated in the execution directory. |
| -S or --settings | -S xprofiler.trace.json | off | xprofiler reads a JSON file containing the events that need to be traced. If this parameter is not configured, xprofiler enables `--profile-api-trace` and `--sse-trace` by default. |
| -A or --profiler-api-trace | -A | on | Get driver events. |
| -s or --sse-trace | -s | on | Get all SSE events. |
| -C or --cluster-trace | -C | off | Retrieve all cluster events. |
| -n or --sdnn-trace | -n | off | Get all SDNN events. |
| -c or --sdnn-cluster-trace | -c | off | Retrieve all SDNN cluster events. |
| -E or --cache-trace | -E | off | Get bandwidth statistics events. |
| -u or --debug | -u44:open log，debug level-u0:close log | 33 | Debug the interface and enable driver event/device event logging.。 |
#### 3.View Results
The generated xprofiler.trace.json file can be viewed and analyzed using a visual interface. Two tools are introduced here.
##### Chrome browser
Enter chrome://tracing/ in your browser (you may need to enable developer tools the first time you access this site), and click "load" in the top left corner to import the file. Interface display.
![img](https://rte.weiyun.baidu.com/wiki/attach/image/api/imageDownloadAddress?attachId=89aef70f112a4394adcac8b03ef994db&docGuid=WFoZOcuqnSXJIE)
##### prefetto ui
Search directly, or visit[Perfetto UI](https://ui.perfetto.dev/#!/viewer?local_cache_key)，The interface is as follows。
![img](https://rte.weiyun.baidu.com/wiki/attach/image/api/imageDownloadAddress?attachId=895a715344e9473c9ee93518c3064b27&docGuid=WFoZOcuqnSXJIE)
#### 4.Performance Analysis
With various performance data available, analysis and optimization can then be performed based on the results.
(Further details to be added later)

199
docs/source/developer_guide/performance/performance_benchmark/benchmark_server.md Normal file
View File

@@ -0,0 +1,199 @@
## vLLM server performance
### vLLM benchmark CLI
You can directly use vLLM's CLI benchmark. For more details, please refer to[vLLM Developer Guide Benchmark Suites](https://docs.vllm.ai/en/stable/contributing/benchmarks.html)
#### 1.Online testing
##### 1.1Start the vLLM server
Server startup script reference
```bash
USE_ORI_ROPE=1 VLLM_USE_V1=1 python -m vllm.entrypoints.openai.api_server \
--host 0.0.0.0 \
--port xxxx \
--model /xxxx/xxxx/model\
--gpu-memory-utilization 0.9 \
--trust-remote-code \
--max-model-len 32768 \
--tensor-parallel-size 1 \
--dtype float16 \
--max_num_seqs 128 \
--max_num_batched_tokens 32768 \
--max-seq-len-to-capture 32768 \
--block-size 128 \
--no-enable-prefix-caching \
--no-enable-chunked-prefill \
--distributed-executor-backend mp \
--served-model-name modelname \
--compilation-config '{"splitting_ops": ["vllm.unified_attention_with_output_kunlun",
"vllm.unified_attention", "vllm.unified_attention_with_output",
"vllm.mamba_mixer2"]}' \
```
##### 1.2Execute test
To run the test script, you can refer to the code below.
```bash
#!/bin/bash
# Run benchmark tests
python -m vllm.entrypoints.cli.main bench serve \
--host 127.0.0.1 \
--port xxxx \
--backend vllm \
--model modelname \
--dataset-name random \
--num-prompts 500 \
--random-input-len 1024 \
--random-output-len 1024 \
--tokenizer /xxxx/xxxx/model \
--ignore-eos 2>&1 | tee benchmark.log
```
##### 1.3Result
The following content will be displayed after the process is complete.
```bash
========== Serving Benchmark Result ==========
Successful requests: 500
Benchmark duration (s): 144.89
Total input tokens: 510414
Total generated tokens: 512000
Request throughput (req/s): 3.45
Output token throughput (tok/s): 3533.68
Total Token throughput (tok/s): 7056.42
----------Time to First Token----------
Mean TTFT (ms): 57959.61
Median TTFT (ms): 43551.93
P99 TTFT (ms): 116202.52
----------Time per Output Token (excl. 1st token)----------
Mean TPOT (ms): 33.30
Median TPOT (ms): 34.15
P99 TPOT (ms): 35.59
----------Inter-token Latency----------
Mean ITL (ms): 33.30
Median ITL (ms): 29.05
P99 ITL (ms): 46.14
============================================
```
Key Parameter Explanation:
| index | meaning | Optimization Objective |
| --------------------------- | ------------------------------------| ---------- |
| ***\*Output Throughput\**** | Output token generation rate | ↑ The higher the better |
| ***\*Mean TTFT\**** | First Token Delay (Time To First Token) | ↓ The lower the better |
| ***\*P99 TTFT\**** | 99% of requests have delayed first token. | ↓ The lower the better |
| ***\*Mean TPOT\**** | Average generation time per output token | ↓ The lower the better |
| ***\*P99 TPOT\**** | 99% of requests' time per token generation | ↓ The lower the better |
| ***\*ITL\**** | Delay between adjacent output tokens | ↓ The lower the better |
#### 2.Offline testing
Comming soon...
### EvalScope
EvalScope is a comprehensive model testing tool that can test not only model accuracy but also performance. For more information, please visit [website address missing].[EvalScope](https://evalscope.readthedocs.io/en/latest/index.html)，A brief introduction follows.
#### 1.Download and install
EvalScope supports use in Python environments. Users can install EvalScope via pip or from source code. Here are examples of both installation methods:
```bash
#pip
pip install evalscope[perf] -U
#git
git clone https://github.com/modelscope/evalscope.git
cd evalscope
pip install -e '.[perf]'
```
After downloading, some modules may be missing, causing the program to fail to run. Just follow the prompts to install them.
#### 2.Start using
The following demonstrates the performance test of the Qwen3-8B in a single-card scenario.
##### 2.1Start the server
The first step is to start the server. The example script is shown below.
```bash
USE_ORI_ROPE=1 VLLM_USE_V1=1 python -m vllm.entrypoints.openai.api_server \
--host 0.0.0.0 \
--port xxxx \
--model /xxxx/xxxx/Qwen3-8B\
--gpu-memory-utilization 0.9 \
--trust-remote-code \
--max-model-len 32768 \
--tensor-parallel-size 1 \
--dtype float16 \
--max_num_seqs 128 \
--max_num_batched_tokens 32768 \
--max-seq-len-to-capture 32768 \
--block-size 128 \
--no-enable-prefix-caching \
--no-enable-chunked-prefill \
--distributed-executor-backend mp \
--served-model-name Qwen3-8B \
--compilation-config '{"splitting_ops": ["vllm.unified_attention_with_output_kunlun",
"vllm.unified_attention", "vllm.unified_attention_with_output",
"vllm.mamba_mixer2"]}' \
```
##### 2.2 Start EvalScope
Start EvalScope to begin performance testing.
```bash
evalscope perf \
--parallel 1 10\#The number of concurrent requests can be tested at once, separated by spaces.
--number 10 20\#The total number of requests per request, aligned with spaces and the concurrency count.
--model Qwen3-8B \
--url http://127.0.0.1:xxxx/v1/chat/completions \
--api openai \
--dataset random \
--max-tokens 1024 \
--min-tokens 1024 \
--prefix-length 0 \
--min-prompt-length 1024 \
--max-prompt-length 1024 \
--tokenizer-path /xxxx/xxxx/Qwen3-8B\
--extra-args '{"ignore_eos": true}'
```
##### 2.3Results Analysis
The following figure shows the results. You can view other data from a single test through the logs. For the specific meaning of the parameters, please refer to the parameter interpretation in the vLLM benchmark test.
```bash
Performance Test Summary Report
Basic Information:
+-------------------+------------------------+
| Model | Qwen3-8B |
| Total Generated | 30,720.0 tokens |
| Total Test Time | 199.79 seconds |
| Avg Output Rate | 153.76 tokens/sec |
+-------------------+------------------------+
Detailed Performance Metrics
+-------+------+------------+------------+-----------+-----------+-----------+-----------+-----------+---------------+
| Conc. | RPS | Avg Lat.(s)| P99 Lat.(s)| Gen. Toks/s| Avg TTFT(s)| P99 TTFT(s)| Avg TPOT(s)| P99 TPOT(s)| Success Rate |
+-------+------+------------+------------+-----------+-----------+-----------+-----------+-----------+---------------+
| 1 | 0.07 | 16.191 | 16.475 | 70.40 | 0.080 | 0.085 | 0.016 | 0.016 | 100.0% |
| 10 | 0.53 | 18.927 | 19.461 | 540.87 | 0.503 | 0.562 | 0.018 | 0.019 | 100.0% |
+-------+------+------------+------------+-----------+-----------+-----------+-----------+-----------+---------------+
Best Performance Configuration
Highest RPS: Concurrency 10 (0.53 req/sec)
Lowest Latency: Concurrency 1 (16.191 seconds)
Performance Recommendations:
* The system seems not to have reached its performance bottleneck, try higher concurrency
```

11
docs/source/developer_guide/performance/performance_benchmark/index.md Normal file
View File

@@ -0,0 +1,11 @@
# Performance_benchmark
This document details the performance testing methods for vllm-kunlun and the analysis of the results to ultimately optimize performance. The main considerations are server throughput and operator performance.
:::{toctree}
:caption: Performance
:maxdepth: 1
benchmark_server
benchmark_kernel
profiling
:::

418
docs/source/developer_guide/performance/performance_benchmark/profiling.md Normal file
View File

@@ -0,0 +1,418 @@
## Profiling
### 🔧 Action Plan（Three Phases）
#### Phase 1️⃣: Multi-Device Log Redirection Configuration
##### Background
By default, kernel logs from all 8 XPU devices are interleaved and emitted to [stdout], resulting in:
- It becomes impossible to distinguish which log originates from which device.
- Timestamps become interleaved, making it difficult to analyze the temporal relationships.
- Single-device bottlenecks are masked by global aggregation.
##### Solution
During model initialization, create separate log files for each device.
##### Code Explanation (embedded in qwen2.py)
```python
import os # ← Ensure this is imported at the top of the file
from vllm.distributed import get_tensor_model_parallel_rank # ← Import function to get the tensor model parallel rank
class Qwen2Model(nn.Module):
def __init__(self,
*,
vllm_config: VllmConfig,
prefix: str = "",
decoder_layer_type: type[nn.Module] = Qwen2DecoderLayer):
super().__init__()
# ========== [Expert Solution] Kunlun XPU Multi-Device Log Redirection ==========
try:
# Step 1: Get the current XPU device's rank (0~7)
rank = get_tensor_model_parallel_rank()
# Step 2: Create log directory (works with your get_kernel_time_ex.py)
log_dir = "./xpu_logs"
os.makedirs(log_dir, exist_ok=True)
# Step 3: Generate a separate log file for each device
log_file = os.path.join(log_dir, f"rank_{rank}.log")
# Step 4: Core operation – redirect file descriptors
# os.O_TRUNC: Clear previous logs on each run to avoid mixing outputs
fd = os.open(log_file, os.O_WRONLY | os.O_CREAT | os.O_TRUNC, 0o664)
os.dup2(fd, 1) # Redirect stdout → rank_X.log
os.dup2(fd, 2) # Redirect stderr → rank_X.log
os.close(fd) # Close original file descriptor; redirection persists
# Optional: print a confirmation message (will go into rank_X.log)
print(f"[Qwen2Model Init] Rank {rank} log redirected to {log_file}")
except Exception as e:
# Fallback mechanism: failure to redirect logs does not affect model loading
print(f"[WARNING] Failed to redirect log for rank: {e}", flush=True)
# ========== End of log redirection code ==========
```
##### ⚠️ Common Issues
**Q1**:Why not use Python's `logging` module?
**A**:The XPU runtime kernel logs are emitted from the C++ layer and cannot be captured by Python’s `logging` module. Redirection via low-level file descriptors is required.
**Q1**:Will logs be lost if the model fails to load??
**A**:The `try-except` block ensures that if log redirection fails, it falls back to the default behavior without affecting model startup.
#### Phase 2️⃣: Profiling Environment Activation
##### 🚀 vLLM Launch
```bash
unset XPU_DUMMY_EVENT
export XPU_VISIBLE_DEVICES=0,1,2,3,4,5,6,7
export XPU_USE_MOE_SORTED_THRES=1
export XFT_USE_FAST_SWIGLU=1
export XMLIR_CUDNN_ENABLED=1
export XPU_USE_DEFAULT_CTX=1
export XMLIR_FORCE_USE_XPU_GRAPH=1
export XPU_USE_FAST_SWIGLU=1
export VLLM_HOST_IP=$(hostname -i)
echo "VLLM_HOST_IP: $VLLM_HOST_IP"
export XMLIR_ENABLE_MOCK_TORCH_COMPILE=false
export XPUAPI_DEBUG=0x1 # Enable kernel performance logging
export XPURT_DISPATCH_MODE=PROFILING # Activate profiling mode
USE_ORI_ROPE=1 VLLM_USE_V1=1 python -m vllm.entrypoints.openai.api_server \
      --host 0.0.0.0 \
      --port 8000 \
      --model /models/Qwen2.5-72B-Instruct \
      --gpu-memory-utilization 0.9 \
      --trust-remote-code \
      --max-model-len 32768 \
      --tensor-parallel-size 8 \
      --dtype float16 \
      --max_num_seqs 512 \
      --max_num_batched_tokens 32768 \
      --max-seq-len-to-capture 32768 \
      --block-size 128 \
      --no-enable-prefix-caching \
      --no-enable-chunked-prefill \
      --distributed-executor-backend mp \
      --served-model-name Qwen2.5-72B-Instruct \
      --compilation-config '{"splitting_ops": ["vllm.unified_attention_with_output_kunlun",
"vllm.unified_attention", "vllm.unified_attention_with_output",
"vllm.mamba_mixer2"]}' 2>&1 | tee output_p800.log
```
##### 🚀 Client Load Testing
```bash
#!/bin/bash
# Define test combinations array (concurrency x input length x output length)
TEST_COMBINATIONS=(
"8x1024x1024" # Medium-low concurrency
)
# Create result directory
RESULT_DIR="bench_$(date +%Y%m%d_%H%M)"
mkdir -p $RESULT_DIR
# Summary results file
SUMMARY_FILE="$RESULT_DIR/summary_results.csv"
echo "num_prompts,input_len,output_len,throughput,latency_mean,latency_p50,latency_p90,latency_p99" >$SUMMARY_FILE
# Progress counter
TOTAL_TESTS=${#TEST_COMBINATIONS[@]}
CURRENT_TEST=0
# Loop through different test combinations
for COMBINATION in "${TEST_COMBINATIONS[@]}"; do
# Parse combination parameters
NUM_PROMPTS=$(echo $COMBINATION | cut -d'x' -f1)
INPUT_LEN=$(echo $COMBINATION | cut -d'x' -f2)
OUTPUT_LEN=$(echo $COMBINATION | cut -d'x' -f3)
# Update progress
CURRENT_TEST=$((CURRENT_TEST + 1))
echo "=========================================================="
echo "Test progress: $CURRENT_TEST/$TOTAL_TESTS ($(printf "%.1f" $(echo "$CURRENT_TEST/$TOTAL_TESTS*100" | bc -l))%)"
echo "Current test configuration: concurrency=$NUM_PROMPTS, input length=$INPUT_LEN, output length=$OUTPUT_LEN"
echo "=========================================================="
OUTPUT_FILE="$RESULT_DIR/p800_${NUM_PROMPTS}_${INPUT_LEN}_${OUTPUT_LEN}.log"
# Run benchmark
python3 -m vllm.entrypoints.cli.main bench serve \
--host 127.0.0.1 \
--port 8000 \
--backend vllm \
--model Qwen2.5-72B-Instruct \
--dataset-name random \
--num-prompts $NUM_PROMPTS \
--random-input-len $INPUT_LEN \
--random-output-len $OUTPUT_LEN \
--tokenizer /ssd1/models/Qwen2.5-72B-Instruct \
--ignore-eos 2>&1 | tee $OUTPUT_FILE
# Wait 15 seconds to let the service recover
echo "Waiting 15 seconds before the next round..."
sleep 15
# Extract key performance metrics from output and append to summary file
THROUGHPUT=$(grep "Throughput" $OUTPUT_FILE | awk '{print $2}')
LATENCY_MEAN=$(grep "Mean latency" $OUTPUT_FILE | awk '{print $3}')
LATENCY_P50=$(grep "p50 latency" $OUTPUT_FILE | awk '{print $3}')
LATENCY_P90=$(grep "p90 latency" $OUTPUT_FILE | awk '{print $3}')
LATENCY_P99=$(grep "p99 latency" $OUTPUT_FILE | awk '{print $3}')
echo "$NUM_PROMPTS,$INPUT_LEN,$OUTPUT_LEN,$THROUGHPUT,$LATENCY_MEAN,$LATENCY_P50,$LATENCY_P90,$LATENCY_P99" >>$SUMMARY_FILE
done
# Output summary report
echo "=========================================================="
echo "Benchmark completed! Results saved in: $RESULT_DIR"
echo "=========================================================="
```
#### Phase 3️⃣: Log Analysis and Bottleneck Identification
```lua
xpu_logs/
├─ rank_0.log
├─ rank_1.log
├─ rank_2.log
├─ rank_3.log
├─ rank_4.log
├─ rank_5.log
├─ rank_6.log
└─ rank_7.log
```
##### 🔍 Script Workflow (op_log.py)
**Input**:Raw Kernel Logs (Sample Format)
```
[XPURT_PROF] void xblas_xpu3::fc_cdnn_infer<float16,...> 123456 ns
[XPURT_PROF] void kl3_all_reduce<float16> 987654 ns
```
**Processing logic**
:::::{tab-set}
::::{tab-item} op_log.py
```python
"""
A better version of 'get_op_time.py', get more level dump and support kl3.
 
Usage: python3 get_kernel_time_ex.py --help
"""
 
import os
import sys
import re
 
unit_factors = [0.9, 1.3, 1.45] # kunlun1, kunlun2, kunlun3
patterns = ["\[XPURT_PROF\] (\S+)\s+\S+\s+(\S+) ns", "\[XPURT_PROF\] (\S+)\s+(\S+)\s+\S+ ns"]
tab_space_num = int(4)
 
def get_total_time(res):
    total_time = 0.0
    for i in res.values():
        total_time += i
    return  total_time
 
def print_info_op(res, cnt, unit, op):
    total_time = get_total_time(res)
    total_cnt = 0
    # print detailed op time
    lis=sorted(res.items(), key=lambda d:d[1], reverse=True)
    if sys.version_info.major == 2:
        import commands
        for i in range(len(lis)):
            (status, cmd_output) = commands.getstatusoutput("c++filt {}".format(lis[i][0]))
            if status == 0:
                formt_type = (cmd_output.split('('))[0]
            total_cnt += cnt[lis[i][0]]
    elif sys.version_info.major == 3:
        import subprocess
        for i in range(len(lis)):
            (status, cmd_output) = subprocess.getstatusoutput("c++filt {}".format(lis[i][0]))
            if status == 0:
                formt_type = (cmd_output.split('('))[0]
            total_cnt += cnt[lis[i][0]]
    print(f"{op} {total_time / unit} {total_cnt}")
 
def print_info_kernel(res, cnt, unit):
    total_time = get_total_time(res)
    total_cnt = 0
    print("Total time(ms) is {}".format(total_time / unit))
    # print detailed op time
    lis=sorted(res.items(), key=lambda d:d[1], reverse=True)
    if sys.version_info.major == 2:
        print("{:<90}{:<10}{:<15}{:<15}".format("Op type", "count", "time(ms)", "%"))
        import commands
        for i in range(len(lis)):
            (status, cmd_output) = commands.getstatusoutput("c++filt {}".format(lis[i][0]))
            if status == 0:
                formt_type = (cmd_output.split('('))[0]
            print("{:<90}{:<10}{:<15}{:<15.5}".format(formt_type, cnt[lis[i][0]], lis[i][1] / unit, \
                lis[i][1] / total_time * 100))
            total_cnt += cnt[lis[i][0]]
    elif sys.version_info.major == 3:
        print("{:<90}{:<10}{:<20}{:<20}".format("Op type", "count", "time(ms)", "%"))
        import subprocess
        for i in range(len(lis)):
            (status, cmd_output) = subprocess.getstatusoutput("c++filt {}".format(lis[i][0]))
            if status == 0:
                formt_type = (cmd_output.split('('))[0]
            print("{:<150}{:<10}{:<25}{:<20.5}".format(formt_type, cnt[lis[i][0]], lis[i][1] / unit, \
                lis[i][1] / total_time * 100))
            total_cnt += cnt[lis[i][0]]
 
    print("Total count is {}".format(total_cnt))
 
def count_head_spaces(s: str) -> int:
   
    count = 0
    for char in s:
        if char == ' ':
            count += 1
        else:
            break
    return count
 
def process_line(lines, pattern1, unit_factor, dump_level):
    """ process a line in a file with profiling info
 
    Args:
        unit_factor: A factor differentiated by KUNLUN1 and KUNLUN2
 
    """
    res = {}
    cnt = {}
    op = "init_op"
    unit = unit_factor * 1000 * 1000 # ns -> ms
    wait_next_one = False
    for i in range(len(lines)):
        cur_line = lines[i]
        if "gtest_" in cur_line:
            cur_level = count_head_spaces(cur_line) / tab_space_num
            if cur_level == dump_level:
                wait_next_one = False
                print_info_op(res, cnt, unit, op)
                # clear buf
                res = {}
                cnt = {}
                op = cur_line.lstrip().rstrip()
            elif cur_level < dump_level:
                wait_next_one = True
                # skip record kernel time untime next one
                continue
        if wait_next_one:
            # skip record kernel time
            continue
        match = re.match(pattern1, lines[i])
        if match:
            op_type = match.group(1)
            op_time = match.group(2)
            if op_type in res:
                res[op_type] += float(op_time)
                cnt[op_type] += 1
            else:
                res[op_type] = float(op_time)
                cnt[op_type] = 1
 
    # get left total time
    if dump_level == -1:
        print_info_kernel(res, cnt, unit)
    else:
        print_info_op(res, cnt, unit, op)
    return res
 
def process_file(file_name, pattern2, unit_factor, dump_level = -1):
    """ Process a file line by line
 
    Iteratively process each line in the target file.
 
    """
 
    with open(file_name, "r") as f:
        lines = f.readlines()
        f1_res_list = process_line(lines, pattern2, unit_factor, dump_level)
 
if __name__ == '__main__':
    import argparse
 
    parser = argparse.ArgumentParser()
 
    group = parser.add_mutually_exclusive_group()
    group.add_argument('-xpu1', action='store_true', help='指定为 xpu1')
    group.add_argument('-xpu2', action='store_true', help='指定为 xpu2')
    group.add_argument('-xpu3', action='store_true', help='指定为 xpu3')
    parser.add_argument('--level', type=int, default=-1, help='指定 dump 缩进级别（默认为 -1）')
    parser.add_argument('filename', help='要处理的文件名')
 
    args = parser.parse_args()
 
    filename = args.filename
    xpu_version = 0
    if args.xpu2:
        xpu_version = 1
    if args.xpu3:
        xpu_version = 2
    dump_level = args.level
    print(f'Filename: {filename}')
    print(f'-xpu option: {xpu_version}')
    print(f'--level option: {dump_level}')
 
    unit_factor = unit_factors[xpu_version]
    pattern_idx = 0
    if xpu_version > 0:
        pattern_idx = 1
    process_file(filename, patterns[pattern_idx], unit_factor, dump_level)
 
```
::::
::::{tab-item} op_log.sh
```bash
for i in {0..7}; do
    python op_log.py -xpu3 xpu_logs/rank_${i}.log > analysis_rank${i}.log
    echo "Rank ${i} 分析完成"
done
for i in {0..7}; do
    echo "=== Rank $i ===" 
    head -n 6 analysis_rank${i}.log | tail -n 5
done
```
::::
:::::
##### 📈 Output Example (analysis_rank0.log)
```
Filename: xpu_logs/rank_0.log
-xpu option: 2
--level option: -1
Total time(ms) is 53742.29571862069
Op type                                                                                   count     time(ms)            %                   
void xblas_xpu3::fc_cdnn_infer<float16, float16, float16, float16, float, float, float, float, 1>                                                     661569    22736.262780689656       42.306              
void kl3_all_reduce<float16>                                                                                                                          176134    14782.525712413793       27.506              
void kl3_all_reduce_butterfly<float16>                                                                                                                164864    4197.28395862069         7.81           
```
##### 🚨 Troubleshooting Guide
|Symptom|Cause|Solution|
|-|-|-|
|`xpu_logs` directory is empty|XPUAPI_DEBUG not enabled|Verify that the environment variable is correctly set|
All 8 log files have identical content|Multi-process backend not activated|Ensure `--distributed-executor-backend` mp is specified|
|Throughput drops >15%|Profiling overhead too high|Enable profiling only during analysis; disable in production|